* bottlenecks
@ 2022-12-16 17:10 Hans Hagen via ntg-context
2022-12-16 19:36 ` bottlenecks Henning Hraban Ramm via ntg-context
2022-12-18 13:14 ` bottlenecks mf via ntg-context
0 siblings, 2 replies; 19+ messages in thread
From: Hans Hagen via ntg-context @ 2022-12-16 17:10 UTC (permalink / raw)
To: mailing list for ConTeXt users; +Cc: Hans Hagen
Hi,
I'm (occasionally) trying to 'minimize' bottlenecks in the context /
luametatex code. This is kind of hard because both are rather efficient
already. On regular runs performance is probably okay but there are
cases when one has a large complex document (e.g. with many tables) or
has many runs (e.g. thousands of documents in one go). In that case even
minor speedups can accumulate and become measurable (esp on vms and runs
over a network). It can safe time and also energy (which can matter
todays KWh pricing).
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?
Hans
ps. Much runtime is spent in Lua and there is not that much we can do
about making that faster.
-----------------------------------------------------------------
Hans Hagen | PRAGMA ADE
Ridderstraat 27 | 8061 GH Hasselt | The Netherlands
tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl
-----------------------------------------------------------------
___________________________________________________________________________________
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
___________________________________________________________________________________
^ permalink raw reply [flat|nested] 19+ messages in thread* Re: bottlenecks 2022-12-16 17:10 bottlenecks Hans Hagen via ntg-context @ 2022-12-16 19:36 ` Henning Hraban Ramm via ntg-context 2022-12-16 20:02 ` bottlenecks Hans Hagen via ntg-context 2022-12-18 13:14 ` bottlenecks mf via ntg-context 1 sibling, 1 reply; 19+ messages in thread From: Henning Hraban Ramm via ntg-context @ 2022-12-16 19:36 UTC (permalink / raw) To: Hans Hagen via ntg-context; +Cc: Henning Hraban Ramm 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-16 19:36 ` bottlenecks Henning Hraban Ramm via ntg-context @ 2022-12-16 20:02 ` Hans Hagen via ntg-context 2022-12-16 21:08 ` bottlenecks Rik Kabel via ntg-context 2022-12-17 16:02 ` bottlenecks Henning Hraban Ramm via ntg-context 0 siblings, 2 replies; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-16 20:02 UTC (permalink / raw) To: Henning Hraban Ramm via ntg-context; +Cc: Hans Hagen On 12/16/2022 8:36 PM, Henning Hraban Ramm via ntg-context wrote: > 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 > runtime: 30.592 seconds, 366 processed pages, 366 > shipped pages, 11.964 pages/second > (2) > This is a 720 page novel (first run with this LMTX version, some fonts > were still uncached): > > mkiv lua stats > runtime: 19.275 seconds, 720 processed pages, 720 > shipped pages, 37.355 pages/second so what if you add to the top \enableexperiments[fonts.compact] Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-16 20:02 ` bottlenecks Hans Hagen via ntg-context @ 2022-12-16 21:08 ` Rik Kabel via ntg-context 2022-12-16 22:07 ` bottlenecks Hans Hagen via ntg-context 2022-12-17 16:02 ` bottlenecks Henning Hraban Ramm via ntg-context 1 sibling, 1 reply; 19+ messages in thread From: Rik Kabel via ntg-context @ 2022-12-16 21:08 UTC (permalink / raw) To: ntg-context; +Cc: Rik Kabel [-- Attachment #1.1: Type: text/plain, Size: 10592 bytes --] Hans, Here are the stats for a 346 page book. Fonts are all cached. Compilation is via a make file which processes this as: context --noconsole --overloadmode=error --batchmode --nonstopmode --nosynctex misquotation_bodyonly.mkvi > nul and is run under W11 x64 on an i7-8550U. The only tables are contents and acronyms, and such, nothing complex. No graphics. Compact fonts are enabled. mkiv lua stats > used config file: selfautoparent:/texmf/web2c/texmfcnf.lua mkiv lua stats > used cache path: C:/ConTeXt_LMTX/tex/texmf-cache/luametatex-cache/context/5fe67e0bfe781ce0dde776fb1556f32e mkiv lua stats > resource resolver: loadtime 0.042 seconds, 1 scans with scantime 0.035 seconds, 0 shared scans, 37 found files, scanned paths: C:/Users/micro/texmf mkiv lua stats > stored bytecode data: 507 modules (0.236 sec), 106 tables (0.015 sec), 613 chunks (0.251 sec) mkiv lua stats > traced context: maxstack: 4107, freed: 2452, unreachable: 1655 mkiv lua stats > cleaned up reserved nodes: 78 nodes, 8 lists of 438 mkiv lua stats > node memory usage: 6869 attribute, 4608 dir, 4612 glue, 84 gluespec, 2304 glyph, 3072 hlist, 3 kern, 647 mathspec, 5 penalty, 2 temp mkiv lua stats > node list callback tasks: 13 unique task lists, 37 instances (re)created, 87130 calls mkiv lua stats > h-node processing time: 3.010 seconds including kernel mkiv lua stats > inserted spaces in output: 106016 mkiv lua stats > attribute processing time: 0.236 seconds front- and backend mkiv lua stats > driver time: 2.099 seconds mkiv lua stats > used backend: pdf mkiv lua stats > jobdata time: 0.191 seconds saving, 0.051 seconds loading mkiv lua stats > callbacks: file: 34388, saved: 191153, direct: 8, function: 173575, value: 345, message: 0, bytecode: 613, late 0, total: 400082 (1184 per page) mkiv lua stats > randomizer: resumed with value 0.88558194690977 mkiv lua stats > v-node processing time: 0.194 seconds mkiv lua stats > loaded patterns: agr:gr:62 cn::58 de::3 deo:de:9 en::1 es::64 fr::63 it::66 la::67 ru::22, load time: 0.000 mkiv lua stats > structure elements: 28145 element chains identified mkiv lua stats > interactive elements: 3982 references, 4873 destinations mkiv lua stats > margin data: 497 entries, 0 pending mkiv lua stats > loaded fonts: 14 files: antykwatorunska-bold.otf, antykwatorunskacond-bold.otf, antykwatorunskacond-regular.otf, libertinusmath-regular.otf, libertinusmono-regular.otf, libertinussans-italic.otf, libertinussans-regular.otf, libertinusserif-italic.otf, libertinusserif-regular.otf, libertinusserif-semibold.otf, zentb___.otf, keteraramtsova.ttf, msjh.ttc, times.ttf mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 instances, 67 shared in backend, 3 common vectors, 64 common hashes, load time 0.947 seconds mkiv lua stats > text directions: 4.273 seconds mkiv lua stats > math tweaking time: 0.152 seconds, 18 math goodie tables mkiv lua stats > pdf annotations: 3982 links (3982 unique), 0 special mkiv lua stats > font embedding time: 0.058 seconds, 13 fonts mkiv lua stats > result saved in file: misquotation_bodyonly.pdf, compresslevel 1, objectcompresslevel 3 mkiv lua stats > positions: 4034 collected, 1722 deltas, 4025 shared partials, 112 partial entries mkiv lua stats > used platform: win64, type: windows, binary subtree: texmf-win64 mkiv lua stats > used engine: luametatex version: 2.1004, functionality level: 20221214, format id: 679, compiler: gcc mkiv lua stats > tex properties: 740852 hash slots used of 2097152, 51846 control sequences, approximate memory usage: 73 MB mkiv lua stats > lua properties: engine: lua 5.4, used memory: 315 MB, ctx: 288 MB, max: 288 MB, symbol mask: utf (τεχ) mkiv lua stats > runtime: 19.332 seconds, 338 processed pages, 338 shipped pages, 17.484 pages/second and here are the stats for the same book with pdf images replacing some of the text (I still don't have rights to some images, so preparing either way): mkiv lua stats > used config file: selfautoparent:/texmf/web2c/texmfcnf.lua mkiv lua stats > used cache path: C:/ConTeXt_LMTX/tex/texmf-cache/luametatex-cache/context/5fe67e0bfe781ce0dde776fb1556f32e mkiv lua stats > resource resolver: loadtime 0.044 seconds, 1 scans with scantime 0.037 seconds, 0 shared scans, 62 found files, scanned paths: C:/Users/micro/texmf mkiv lua stats > stored bytecode data: 507 modules (0.236 sec), 106 tables (0.015 sec), 613 chunks (0.251 sec) mkiv lua stats > traced context: maxstack: 4112, freed: 2457, unreachable: 1655 mkiv lua stats > cleaned up reserved nodes: 78 nodes, 8 lists of 438 mkiv lua stats > node memory usage: 6869 attribute, 4608 dir, 4612 glue, 84 gluespec, 2304 glyph, 3072 hlist, 3 kern, 647 mathspec, 5 penalty, 2 temp mkiv lua stats > node list callback tasks: 13 unique task lists, 37 instances (re)created, 86856 calls mkiv lua stats > h-node processing time: 2.899 seconds including kernel mkiv lua stats > inserted spaces in output: 104350 mkiv lua stats > attribute processing time: 0.225 seconds front- and backend mkiv lua stats > driver time: 2.050 seconds mkiv lua stats > used backend: pdf mkiv lua stats > jobdata time: 0.210 seconds saving, 0.053 seconds loading mkiv lua stats > callbacks: file: 34137, saved: 190338, direct: 33, function: 173845, value: 337, message: 0, bytecode: 613, late 0, total: 399303 (1188 per page) mkiv lua stats > randomizer: resumed with value 0.88558194690977 mkiv lua stats > v-node processing time: 0.266 seconds mkiv lua stats > loaded patterns: agr:gr:62 cn::58 de::3 deo:de:9 en::1 es::64 fr::63 it::66 la::67 ru::22, load time: 0.000 mkiv lua stats > structure elements: 28023 element chains identified mkiv lua stats > interactive elements: 3997 references, 4875 destinations mkiv lua stats > margin data: 497 entries, 0 pending mkiv lua stats > loaded fonts: 14 files: antykwatorunska-bold.otf, antykwatorunskacond-bold.otf, antykwatorunskacond-regular.otf, libertinusmath-regular.otf, libertinusmono-regular.otf, libertinussans-italic.otf, libertinussans-regular.otf, libertinusserif-italic.otf, libertinusserif-regular.otf, libertinusserif-semibold.otf, zentb___.otf, keteraramtsova.ttf, msjh.ttc, times.ttf mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 instances, 67 shared in backend, 3 common vectors, 64 common hashes, load time 0.991 seconds mkiv lua stats > text directions: 4.016 seconds mkiv lua stats > math tweaking time: 0.155 seconds, 18 math goodie tables mkiv lua stats > graphics processing time: 3.767 seconds including tex, 25 processed images, 25 unique asked, 25 bad names mkiv lua stats > pdf annotations: 3997 links (3997 unique), 0 special mkiv lua stats > font embedding time: 0.061 seconds, 12 fonts mkiv lua stats > result saved in file: misquotation_bodyonly.pdf, compresslevel 1, objectcompresslevel 3 mkiv lua stats > positions: 3983 collected, 1672 deltas, 3973 shared partials, 110 partial entries mkiv lua stats > used platform: win64, type: windows, binary subtree: texmf-win64 mkiv lua stats > used engine: luametatex version: 2.1004, functionality level: 20221214, format id: 679, compiler: gcc mkiv lua stats > tex properties: 740852 hash slots used of 2097152, 51853 control sequences, approximate memory usage: 73 MB mkiv lua stats > lua properties: engine: lua 5.4, used memory: 221 MB, ctx: 195 MB, max: 219 MB, symbol mask: utf (τεχ) mkiv lua stats > runtime: 23.057 seconds, 336 processed pages, 336 shipped pages, 14.572 pages/second Significant time is attributed to text directions (there are a few excerpts in Hebrew), and to graphics processing in the second case. In neither case do the sum of the times listed in the stats come close to the total runtime (in the second example, 14.774 seconds of 23.057 are accounted), so there are other unidentified processes involved. In any case, the processing time has been improving greatly over the last couple of years, and LMTX is significantly faster that MkIV in all of my work. -- Rik On 2022-12-16 15:02, Hans Hagen via ntg-context wrote: > On 12/16/2022 8:36 PM, Henning Hraban Ramm via ntg-context wrote: >> 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 > runtime: 30.592 seconds, 366 processed pages, 366 >> shipped pages, 11.964 pages/second > >> (2) >> This is a 720 page novel (first run with this LMTX version, some >> fonts were still uncached): >> > >> mkiv lua stats > runtime: 19.275 seconds, 720 processed pages, 720 >> shipped pages, 37.355 pages/second > so what if you add to the top > > \enableexperiments[fonts.compact] > > Hans > > ----------------------------------------------------------------- > Hans Hagen | PRAGMA ADE > Ridderstraat 27 | 8061 GH Hasselt | The Netherlands > tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl > ----------------------------------------------------------------- > > ___________________________________________________________________________________ > > 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 > ___________________________________________________________________________________ > [-- Attachment #1.2: Type: text/html, Size: 13759 bytes --] [-- Attachment #2: Type: text/plain, Size: 496 bytes --] ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-16 21:08 ` bottlenecks Rik Kabel via ntg-context @ 2022-12-16 22:07 ` Hans Hagen via ntg-context 2022-12-17 0:05 ` bottlenecks Rik Kabel via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-16 22:07 UTC (permalink / raw) To: Rik Kabel via ntg-context; +Cc: Hans Hagen On 12/16/2022 10:08 PM, Rik Kabel via ntg-context wrote: > Hans, > > Here are the stats for a 346 page book. Fonts are all cached. > Compilation is via a make file which processes this as: > > context --noconsole --overloadmode=error --batchmode --nonstopmode > --nosynctex misquotation_bodyonly.mkvi > nul > > and is run under W11 x64 on an i7-8550U. The only tables are contents ok, not the fastest i7 out there, more the tablet one, right? > and acronyms, and such, nothing complex. No graphics. Compact fonts are > enabled. can you check compact mode .. when compact fonts are not enabled, do you get the same > mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 > instances, 67 shared in backend, 3 common vectors, 64 common hashes, i wonder why so many instances > mkiv lua stats > node memory usage: 6869 attribute, 4608 dir, 4612 > glue, 84 gluespec, 2304 glyph, 3072 hlist, 3 kern, 647 mathspec, 5 > penalty, 2 temp this is suspicious ... i fixed a dir leak recently but having 3K boxes dangling ... > In neither case do the sum of the times listed in the stats come close > to the total runtime (in the second example, 14.774 seconds of 23.057 > are accounted), so there are other unidentified processes involved. these stats are an indication because below a threshold (time accuracy) nothing is measured > In any case, the processing time has been improving greatly over the > last couple of years, and LMTX is significantly faster that MkIV in all > of my work. sure, that is to be expected although it depends a bit on the use case, for instance the backend is slower (but does much more) so initially lmtx was actually slower but at some point we started gaining (and i can probably gain a little more) i wonder why directions bump time because much of what tex does is sort of agnostic for directions (the backend needs more time but i don't see that in your stats) when you run with --profile you get a much slower run but might get some info from the extra log Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-16 22:07 ` bottlenecks Hans Hagen via ntg-context @ 2022-12-17 0:05 ` Rik Kabel via ntg-context 2022-12-17 9:48 ` bottlenecks Hans Hagen via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: Rik Kabel via ntg-context @ 2022-12-17 0:05 UTC (permalink / raw) To: ntg-context; +Cc: Rik Kabel [-- Attachment #1.1: Type: text/plain, Size: 6440 bytes --] On 2022-12-16 17:07, Hans Hagen via ntg-context wrote: > On 12/16/2022 10:08 PM, Rik Kabel via ntg-context wrote: >> Hans, >> >> Here are the stats for a 346 page book. Fonts are all cached. >> Compilation is via a make file which processes this as: >> >> context --noconsole --overloadmode=error --batchmode --nonstopmode >> --nosynctex misquotation_bodyonly.mkvi > nul >> >> and is run under W11 x64 on an i7-8550U. The only tables are contents > > ok, not the fastest i7 out there, more the tablet one, right? > >> and acronyms, and such, nothing complex. No graphics. Compact fonts >> are enabled. > > can you check compact mode .. when compact fonts are not enabled, do > you get the same > > > mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 > > instances, 67 shared in backend, 3 common vectors, 64 common > hashes, > > i wonder why so many instances > >> mkiv lua stats > node memory usage: 6869 attribute, 4608 dir, 4612 >> glue, 84 gluespec, 2304 glyph, 3072 hlist, 3 kern, 647 mathspec, 5 >> penalty, 2 temp > > this is suspicious ... i fixed a dir leak recently but having 3K boxes > dangling ... > >> In neither case do the sum of the times listed in the stats come >> close to the total runtime (in the second example, 14.774 seconds of >> 23.057 are accounted), so there are other unidentified processes >> involved. > > these stats are an indication because below a threshold (time > accuracy) nothing is measured > >> In any case, the processing time has been improving greatly over the >> last couple of years, and LMTX is significantly faster that MkIV in >> all of my work. > sure, that is to be expected although it depends a bit on the use > case, for instance the backend is slower (but does much more) so > initially lmtx was actually slower but at some point we started > gaining (and i can probably gain a little more) > > i wonder why directions bump time because much of what tex does is > sort of agnostic for directions (the backend needs more time but i > don't see that in your stats) > > when you run with --profile you get a much slower run but might get > some info from the extra log > > Hans > The laptop was hot stuff in 2017 with 16GB RAM, 1TB SSD, and a 4K touch screen -- today, not so hot. Due to be replaced next year. Here are the numbers without compact fonts enabled. Not much difference. mkiv lua stats > used config file: selfautoparent:/texmf/web2c/texmfcnf.lua mkiv lua stats > used cache path: C:/ConTeXt_LMTX/tex/texmf-cache/luametatex-cache/context/5fe67e0bfe781ce0dde776fb1556f32e mkiv lua stats > resource resolver: loadtime 0.045 seconds, 1 scans with scantime 0.037 seconds, 0 shared scans, 37 found files, scanned paths: C:/Users/micro/texmf mkiv lua stats > stored bytecode data: 507 modules (0.243 sec), 106 tables (0.016 sec), 613 chunks (0.259 sec) mkiv lua stats > traced context: maxstack: 4107, freed: 2452, unreachable: 1655 mkiv lua stats > cleaned up reserved nodes: 78 nodes, 8 lists of 438 mkiv lua stats > node memory usage: 6869 attribute, 4608 dir, 4612 glue, 84 gluespec, 2304 glyph, 3072 hlist, 3 kern, 647 mathspec, 5 penalty, 2 temp mkiv lua stats > node list callback tasks: 13 unique task lists, 37 instances (re)created, 87130 calls mkiv lua stats > h-node processing time: 3.454 seconds including kernel mkiv lua stats > inserted spaces in output: 106016 mkiv lua stats > attribute processing time: 0.295 seconds front- and backend mkiv lua stats > driver time: 2.487 seconds mkiv lua stats > used backend: pdf mkiv lua stats > jobdata time: 0.290 seconds saving, 0.053 seconds loading mkiv lua stats > callbacks: file: 34388, saved: 191153, direct: 8, function: 173574, value: 345, message: 0, bytecode: 613, late 0, total: 400081 (1184 per page) mkiv lua stats > randomizer: resumed with value 0.88558194690977 mkiv lua stats > v-node processing time: 0.250 seconds mkiv lua stats > loaded patterns: agr:gr:62 cn::58 de::3 deo:de:9 en::1 es::64 fr::63 it::66 la::67 ru::22, load time: 0.000 mkiv lua stats > structure elements: 28145 element chains identified mkiv lua stats > interactive elements: 3982 references, 4873 destinations mkiv lua stats > margin data: 497 entries, 0 pending mkiv lua stats > loaded fonts: 14 files: antykwatorunska-bold.otf, antykwatorunskacond-bold.otf, antykwatorunskacond-regular.otf, libertinusmath-regular.otf, libertinusmono-regular.otf, libertinussans-italic.otf, libertinussans-regular.otf, libertinusserif-italic.otf, libertinusserif-regular.otf, libertinusserif-semibold.otf, zentb___.otf, keteraramtsova.ttf, msjh.ttc, times.ttf mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 instances, 67 shared in backend, 3 common vectors, 64 common hashes, load time 1.076 seconds mkiv lua stats > text directions: 4.987 seconds mkiv lua stats > math tweaking time: 0.187 seconds, 18 math goodie tables mkiv lua stats > pdf annotations: 3982 links (3982 unique), 0 special mkiv lua stats > font embedding time: 0.195 seconds, 13 fonts mkiv lua stats > result saved in file: misquotation_bodyonly.pdf, compresslevel 1, objectcompresslevel 3 mkiv lua stats > positions: 4034 collected, 1722 deltas, 4025 shared partials, 112 partial entries mkiv lua stats > used platform: win64, type: windows, binary subtree: texmf-win64 mkiv lua stats > used engine: luametatex version: 2.1004, functionality level: 20221214, format id: 679, compiler: gcc mkiv lua stats > tex properties: 740852 hash slots used of 2097152, 51846 control sequences, approximate memory usage: 73 MB mkiv lua stats > lua properties: engine: lua 5.4, used memory: 314 MB, ctx: 288 MB, max: 288 MB, symbol mask: utf (τεχ) mkiv lua stats > runtime: 23.731 seconds, 338 processed pages, 338 shipped pages, 14.243 pages/second I do have some macros that are likely to make you (and others who are more adept at such things) cringe. Happy to share more of the source if it is helpful. I have also run with --profile and have attached that log as well as the complete execution log (zipped together as logs.zip). -- Rik [-- Attachment #1.2: Type: text/html, Size: 8291 bytes --] [-- Attachment #2: logs.zip --] [-- Type: application/x-zip-compressed, Size: 69783 bytes --] [-- Attachment #3: Type: text/plain, Size: 496 bytes --] ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-17 0:05 ` bottlenecks Rik Kabel via ntg-context @ 2022-12-17 9:48 ` Hans Hagen via ntg-context 2022-12-17 15:05 ` bottlenecks Rik Kabel via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-17 9:48 UTC (permalink / raw) To: Rik Kabel via ntg-context; +Cc: Hans Hagen On 12/17/2022 1:05 AM, Rik Kabel via ntg-context wrote: > The laptop was hot stuff in 2017 with 16GB RAM, 1TB SSD, and a 4K touch > screen -- today, not so hot. Due to be replaced next year. so a bit like the surface i have as spare (which was slower than the 2013 precission that i recently replaced by a 2018 one) > Here are the numbers without compact fonts enabled. Not much difference. > mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 > instances, 67 shared in backend, 3 common vectors, 64 common hashes, > load time 1.076 seconds which means that you don't run in compact mode > I do have some macros that are likely to make you (and others who are > more adept at such things) cringe. Happy to share more of the source if > it is helpful. sure > I have also run with --profile and have attached that log as well as the > complete execution log (zipped together as logs.zip). here are a few: 0.613002300 s 0.138 % 0.609968531 s 0.160 % 3674 # prerollreference 0.420704300 s 0.095 % 0.420702649 s 0.110 % 2 # analyzeregister 0.425307400 s 0.096 % 0.425299968 s 0.111 % 9 # action 1358 ...MTX/tex/texmf-context/tex/context/base/mkxl/math-act.lmt 0.681407500 s 0.154 % 0.681338138 s 0.178 % 84 # otftotfm 611 ...MTX/tex/texmf-context/tex/context/base/mkxl/font-otl.lmt few calls, much runtime Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-17 9:48 ` bottlenecks Hans Hagen via ntg-context @ 2022-12-17 15:05 ` Rik Kabel via ntg-context 2022-12-17 17:21 ` bottlenecks Hans Hagen via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: Rik Kabel via ntg-context @ 2022-12-17 15:05 UTC (permalink / raw) To: ntg-context; +Cc: Rik Kabel [-- Attachment #1.1: Type: text/plain, Size: 5535 bytes --] On 2022-12-17 04:48, Hans Hagen via ntg-context wrote: > On 12/17/2022 1:05 AM, Rik Kabel via ntg-context wrote: > >> The laptop was hot stuff in 2017 with 16GB RAM, 1TB SSD, and a 4K >> touch screen -- today, not so hot. Due to be replaced next year. > > so a bit like the surface i have as spare (which was slower than the > 2013 precission that i recently replaced by a 2018 one) > >> Here are the numbers without compact fonts enabled. Not much difference. > >> mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 >> instances, 67 shared in backend, 3 common vectors, 64 common hashes, >> load time 1.076 seconds > > which means that you don't run in compact mode Indeed, I had a typo. Running with compact fonts, I get: mkiv lua stats > used config file: selfautoparent:/texmf/web2c/texmfcnf.lua mkiv lua stats > used cache path: C:/ConTeXt_LMTX/tex/texmf-cache/luametatex-cache/context/5fe67e0bfe781ce0dde776fb1556f32e mkiv lua stats > resource resolver: loadtime 0.045 seconds, 1 scans with scantime 0.037 seconds, 0 shared scans, 37 found files, scanned paths: C:/Users/micro/texmf mkiv lua stats > stored bytecode data: 507 modules (0.267 sec), 106 tables (0.015 sec), 613 chunks (0.282 sec) mkiv lua stats > traced context: maxstack: 4108, freed: 2453, unreachable: 1655 mkiv lua stats > cleaned up reserved nodes: 78 nodes, 8 lists of 438 mkiv lua stats > node memory usage: 6860 attribute, 4602 dir, 69 fontspec, 4606 glue, 84 gluespec, 2301 glyph, 3068 hlist, 3 kern, 647 mathspec, 5 penalty, 2 temp mkiv lua stats > node list callback tasks: 13 unique task lists, 37 instances (re)created, 87134 calls mkiv lua stats > h-node processing time: 3.146 seconds including kernel mkiv lua stats > inserted spaces in output: 106025 mkiv lua stats > attribute processing time: 0.248 seconds front- and backend mkiv lua stats > driver time: 2.425 seconds mkiv lua stats > used backend: pdf mkiv lua stats > jobdata time: 0.198 seconds saving, 0.059 seconds loading mkiv lua stats > callbacks: file: 34385, saved: 191160, direct: 8, function: 173538, value: 345, message: 0, bytecode: 613, late 0, total: 400049 (1184 per page) mkiv lua stats > randomizer: resumed with value 0.88558194690977 mkiv lua stats > v-node processing time: 0.208 seconds mkiv lua stats > loaded patterns: agr:gr:62 cn::58 de::3 deo:de:9 en::1 es::64 fr::63 it::66 la::67 ru::22, load time: 0.000 mkiv lua stats > structure elements: 28148 element chains identified mkiv lua stats > interactive elements: 3983 references, 4873 destinations mkiv lua stats > margin data: 497 entries, 0 pending mkiv lua stats > loaded fonts: 14 files: antykwatorunska-bold.otf, antykwatorunskacond-bold.otf, antykwatorunskacond-regular.otf, libertinusmath-regular.otf, libertinusmono-regular.otf, libertinussans-italic.otf, libertinussans-regular.otf, libertinusserif-italic.otf, libertinusserif-regular.otf, libertinusserif-semibold.otf, zentb___.otf, keteraramtsova.ttf, msjh.ttc, times.ttf *mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 18 instances, 2 shared in backend, 2 common vectors, 0 common hashes, load time 0.534 seconds * mkiv lua stats > text directions: 4.229 seconds mkiv lua stats > math tweaking time: 0.023 seconds, 2 math goodie tables mkiv lua stats > pdf annotations: 3983 links (3983 unique), 0 special mkiv lua stats > font embedding time: 0.055 seconds, 13 fonts mkiv lua stats > result saved in file: misquotation_bodyonly.pdf, compresslevel 1, objectcompresslevel 3 mkiv lua stats > positions: 4034 collected, 1723 deltas, 4025 shared partials, 111 partial entries mkiv lua stats > used platform: win64, type: windows, binary subtree: texmf-win64 mkiv lua stats > used engine: luametatex version: 2.1004, functionality level: 20221214, format id: 679, compiler: gcc mkiv lua stats > tex properties: 740852 hash slots used of 2097152, 51822 control sequences, approximate memory usage: 41 MB mkiv lua stats > lua properties: engine: lua 5.4, used memory: 225 MB, ctx: 200 MB, max: 200 MB, symbol mask: utf (τεχ) mkiv lua stats > runtime: 19.993 seconds, 338 processed pages, 338 shipped pages, 16.906 pages/second but the overall runtime is essentially unchanged. >> I do have some macros that are likely to make you (and others who are >> more adept at such things) cringe. Happy to share more of the source >> if it is helpful. > > sure > >> I have also run with --profile and have attached that log as well as >> the complete execution log (zipped together as logs.zip). > here are a few: > > 0.613002300 s 0.138 % 0.609968531 s 0.160 % 3674 # > prerollreference > > 0.420704300 s 0.095 % 0.420702649 s 0.110 % 2 # > analyzeregister > > 0.425307400 s 0.096 % 0.425299968 s 0.111 % 9 # > action 1358 > ...MTX/tex/texmf-context/tex/context/base/mkxl/math-act.lmt > > 0.681407500 s 0.154 % 0.681338138 s 0.178 % 84 # > otftotfm 611 > ...MTX/tex/texmf-context/tex/context/base/mkxl/font-otl.lmt > > few calls, much runtime And that mean what? Does it point to something I should do differently? Is there more detailed information that I can generate for diagnostics that would help? > > Hans > > -- Rik [-- Attachment #1.2: Type: text/html, Size: 7537 bytes --] [-- Attachment #2: Type: text/plain, Size: 496 bytes --] ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-17 15:05 ` bottlenecks Rik Kabel via ntg-context @ 2022-12-17 17:21 ` Hans Hagen via ntg-context 2022-12-17 21:11 ` bottlenecks Alan Braslau via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-17 17:21 UTC (permalink / raw) To: Rik Kabel via ntg-context; +Cc: Hans Hagen On 12/17/2022 4:05 PM, Rik Kabel via ntg-context wrote: > > On 2022-12-17 04:48, Hans Hagen via ntg-context wrote: >> On 12/17/2022 1:05 AM, Rik Kabel via ntg-context wrote: >> >>> The laptop was hot stuff in 2017 with 16GB RAM, 1TB SSD, and a 4K >>> touch screen -- today, not so hot. Due to be replaced next year. >> >> so a bit like the surface i have as spare (which was slower than the >> 2013 precission that i recently replaced by a 2018 one) >> >>> Here are the numbers without compact fonts enabled. Not much difference. >> >>> mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 84 >>> instances, 67 shared in backend, 3 common vectors, 64 common hashes, >>> load time 1.076 seconds >> >> which means that you don't run in compact mode > > Indeed, I had a typo. Running with compact fonts, I get: > > mkiv lua stats > used config file: selfautoparent:/texmf/web2c/texmfcnf.lua > mkiv lua stats > used cache path: > C:/ConTeXt_LMTX/tex/texmf-cache/luametatex-cache/context/5fe67e0bfe781ce0dde776fb1556f32e > mkiv lua stats > resource resolver: loadtime 0.045 seconds, 1 scans > with scantime 0.037 seconds, 0 shared scans, 37 found files, scanned > paths: C:/Users/micro/texmf > mkiv lua stats > stored bytecode data: 507 modules (0.267 sec), 106 > tables (0.015 sec), 613 chunks (0.282 sec) > mkiv lua stats > traced context: maxstack: 4108, freed: 2453, > unreachable: 1655 > mkiv lua stats > cleaned up reserved nodes: 78 nodes, 8 lists of 438 > mkiv lua stats > node memory usage: 6860 attribute, 4602 dir, 69 > fontspec, 4606 glue, 84 gluespec, 2301 glyph, 3068 hlist, 3 kern, 647 > mathspec, 5 penalty, 2 temp > mkiv lua stats > node list callback tasks: 13 unique task lists, 37 > instances (re)created, 87134 calls > mkiv lua stats > h-node processing time: 3.146 seconds including kernel > mkiv lua stats > inserted spaces in output: 106025 > mkiv lua stats > attribute processing time: 0.248 seconds front- and > backend > mkiv lua stats > driver time: 2.425 seconds > mkiv lua stats > used backend: pdf > mkiv lua stats > jobdata time: 0.198 seconds saving, 0.059 seconds loading > mkiv lua stats > callbacks: file: 34385, saved: 191160, direct: 8, > function: 173538, value: 345, message: 0, bytecode: 613, late 0, total: > 400049 (1184 per page) > mkiv lua stats > randomizer: resumed with value 0.88558194690977 > mkiv lua stats > v-node processing time: 0.208 seconds > mkiv lua stats > loaded patterns: agr:gr:62 cn::58 de::3 deo:de:9 en::1 > es::64 fr::63 it::66 la::67 ru::22, load time: 0.000 > mkiv lua stats > structure elements: 28148 element chains identified > mkiv lua stats > interactive elements: 3983 references, 4873 destinations > mkiv lua stats > margin data: 497 entries, 0 pending > mkiv lua stats > loaded fonts: 14 files: antykwatorunska-bold.otf, > antykwatorunskacond-bold.otf, antykwatorunskacond-regular.otf, > libertinusmath-regular.otf, libertinusmono-regular.otf, > libertinussans-italic.otf, libertinussans-regular.otf, > libertinusserif-italic.otf, libertinusserif-regular.otf, > libertinusserif-semibold.otf, zentb___.otf, keteraramtsova.ttf, > msjh.ttc, times.ttf > *mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 18 > instances, 2 shared in backend, 2 common vectors, 0 common hashes, load > time 0.534 seconds * > mkiv lua stats > text directions: 4.229 seconds > mkiv lua stats > math tweaking time: 0.023 seconds, 2 math goodie tables > mkiv lua stats > pdf annotations: 3983 links (3983 unique), 0 special > mkiv lua stats > font embedding time: 0.055 seconds, 13 fonts > mkiv lua stats > result saved in file: misquotation_bodyonly.pdf, > compresslevel 1, objectcompresslevel 3 > mkiv lua stats > positions: 4034 collected, 1723 deltas, 4025 shared > partials, 111 partial entries > mkiv lua stats > used platform: win64, type: windows, binary subtree: > texmf-win64 > mkiv lua stats > used engine: luametatex version: 2.1004, functionality > level: 20221214, format id: 679, compiler: gcc > mkiv lua stats > tex properties: 740852 hash slots used of 2097152, > 51822 control sequences, approximate memory usage: 41 MB > mkiv lua stats > lua properties: engine: lua 5.4, used memory: 225 MB, > ctx: 200 MB, max: 200 MB, symbol mask: utf (τεχ) > mkiv lua stats > runtime: 19.993 seconds, 338 processed pages, 338 > shipped pages, 16.906 pages/second > > but the overall runtime is essentially unchanged. interesting, normally we gain something (ok, at least one gains memory) >>> I do have some macros that are likely to make you (and others who are >>> more adept at such things) cringe. Happy to share more of the source >>> if it is helpful. >> >> sure >> >>> I have also run with --profile and have attached that log as well as >>> the complete execution log (zipped together as logs.zip). >> here are a few: >> >> 0.613002300 s 0.138 % 0.609968531 s 0.160 % 3674 # >> prerollreference >> >> 0.420704300 s 0.095 % 0.420702649 s 0.110 % 2 # >> analyzeregister >> >> 0.425307400 s 0.096 % 0.425299968 s 0.111 % 9 # >> action 1358 >> ...MTX/tex/texmf-context/tex/context/base/mkxl/math-act.lmt >> >> 0.681407500 s 0.154 % 0.681338138 s 0.178 % 84 # >> otftotfm 611 >> ...MTX/tex/texmf-context/tex/context/base/mkxl/font-otl.lmt >> >> few calls, much runtime > > And that mean what? Does it point to something I should do differently? > Is there more detailed information that I can generate for diagnostics > that would help? it's more something i could look into but what does puzzle me are your dir etc leaks and for that we need a test so if you can make a mwe that leaks ... Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-17 17:21 ` bottlenecks Hans Hagen via ntg-context @ 2022-12-17 21:11 ` Alan Braslau via ntg-context 2022-12-17 21:35 ` bottlenecks Hans Hagen via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: Alan Braslau via ntg-context @ 2022-12-17 21:11 UTC (permalink / raw) To: Hans Hagen via ntg-context; +Cc: Alan Braslau With lots of MetaPost, lots of references, lots of figures, lots of tables, lots of bibliography entries, lots of chemical structures, ... mkiv lua stats > used config file: selfautoparent:/texmf/web2c/texmfcnf.lua mkiv lua stats > used cache path: /home/braslau/context/beta/tex/texmf-cache/luametatex-cache/context/5fe67e0bfe781ce0dde776fb1556f32e mkiv lua stats > resource resolver: loadtime 0.003 seconds, 0 scans with scantime 0.000 seconds, 0 shared scans, 98 found files, scanned paths: <none> mkiv lua stats > stored bytecode data: 507 modules (0.117 sec), 106 tables (0.000 sec), 613 chunks (0.117 sec) mkiv lua stats > traced context: maxstack: 5959, freed: 2352, unreachable: 3607 mkiv lua stats > cleaned up reserved nodes: 101 nodes, 15 lists of 439 mkiv lua stats > node memory usage: 2491 attribute, 76 boundary, 84 dir, 1167 glue, 85 gluespec, 430 glyph, 242 hlist, 333 kern, 32 math, 647 mathspec, 238 par, 328 penalty, 88 rule, 2 temp, 100 vlist, 18 whatsit mkiv lua stats > node list callback tasks: 13 unique task lists, 376 instances (re)created, 147276 calls mkiv lua stats > h-node processing time: 4.724 seconds including kernel mkiv lua stats > attribute processing time: 0.202 seconds front- and backend mkiv lua stats > driver time: 1.419 seconds mkiv lua stats > used backend: pdf mkiv lua stats > jobdata time: 0.224 seconds saving, 0.068 seconds loading mkiv lua stats > callbacks: file: 32365, saved: 278423, direct: 486, function: 259776, value: 579, message: 0, bytecode: 613, late 0, total: 572242 (990 per page) mkiv lua stats > randomizer: resumed with value 0.86690391712354 mkiv lua stats > v-node processing time: 0.186 seconds mkiv lua stats > loaded tex modules: 2 requested, all found (*-graph *-three) mkiv lua stats > loaded patterns: de::3 en::1 fr::63, load time: 0.000 mkiv lua stats > interactive elements: 12106 references, 5886 destinations mkiv lua stats > loaded fonts: 5 files: cambria.ttc, cambriab.ttf, cambriai.ttf, dejavusansmono-oblique.ttf, dejavusansmono.ttf mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 73 instances, 65 shared in backend, 5 common vectors, 60 common hashes, load time 1.571 seconds mkiv lua stats > body font sizes: defined: 10pt 11pt 12pt 14.4pt 17.3pt 20.7pt 4pt 5pt 6pt 7pt 8pt 9pt, undefined: 18pt 21.6pt mkiv lua stats > metapost: 1.277 seconds, loading: 0.083, execution: 1.260, n: 881, average: 0.003, instances: 6, luacalls: 108876 (file: 90144, text: 0, script: 10120, log: 8568), memory: 30.514 M mkiv lua stats > math tweaking time: 0.852 seconds, 96 math goodie tables mkiv lua stats > math processing time: 0.158 seconds mkiv lua stats > chemical formulas: 58 chemical structure formulas mkiv lua stats > graphics processing time: 0.414 seconds including tex, 264 processed images, 220 unique asked, 200 bad names mkiv lua stats > publications load time: 0.026 seconds, 584341 bytes, 835 definitions, 14 shortcuts mkiv lua stats > pdf annotations: 12106 links (11765 unique), 0 special mkiv lua stats > font embedding time: 0.016 seconds, 7 fonts mkiv lua stats > result saved in file: Cristaux_Liquides_tome2.pdf, compresslevel 1, objectcompresslevel 3 mkiv lua stats > positions: 2708 collected, 769 deltas, 2645 shared partials, 484 partial entries mkiv lua stats > cross referencing: 13943 identified, 34 unknown mkiv lua stats > used platform: freebsd-amd64, type: unix, binary subtree: texmf-freebsd-amd64 mkiv lua stats > used engine: luametatex version: 2.1004, functionality level: 20221214, format id: 679, compiler: clang mkiv lua stats > tex properties: 740852 hash slots used of 2097152, 50741 control sequences, approximate memory usage: 125 MB mkiv lua stats > lua properties: engine: lua 5.4, used memory: 301 MB, ctx: 275 MB, max: 445 MB, symbol mask: utf (τεχ) mkiv lua stats > runtime: 17.027 seconds, 578 processed pages, 578 shipped pages, 33.946 pages/second system | total runtime: 68.547 seconds of 68.576 seconds Alan ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-17 21:11 ` bottlenecks Alan Braslau via ntg-context @ 2022-12-17 21:35 ` Hans Hagen via ntg-context 2022-12-18 21:35 ` bottlenecks Alan Braslau via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-17 21:35 UTC (permalink / raw) To: Alan Braslau via ntg-context; +Cc: Hans Hagen On 12/17/2022 10:11 PM, Alan Braslau via ntg-context wrote: > With lots of MetaPost, lots of references, lots of figures, lots of tables, lots of bibliography entries, lots of chemical structures, ... > > mkiv lua stats > node memory usage: 2491 attribute, 76 boundary, 84 dir, 1167 glue, 85 gluespec, 430 glyph, 242 hlist, 333 kern, 32 math, 647 mathspec, 238 par, 328 penalty, 88 rule, 2 temp, 100 vlist, 18 whatsit ok, i need to figure out where these lists come from (could be harmless, (mp) caching or so) > mkiv lua stats > runtime: 17.027 seconds, 578 processed pages, 578 shipped pages, 33.946 pages/second that's quite decent i guess > system | total runtime: 68.547 seconds of 68.576 seconds the fact that we have multiple runs make any optimization count for more than on a single run thanks for testing Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-17 21:35 ` bottlenecks Hans Hagen via ntg-context @ 2022-12-18 21:35 ` Alan Braslau via ntg-context 0 siblings, 0 replies; 19+ messages in thread From: Alan Braslau via ntg-context @ 2022-12-18 21:35 UTC (permalink / raw) To: Hans Hagen via ntg-context; +Cc: Alan Braslau On Sat, 17 Dec 2022 22:35:04 +0100 Hans Hagen via ntg-context <ntg-context@ntg.nl> wrote: > > mkiv lua stats > runtime: 17.027 seconds, 578 processed pages, 578 > > shipped pages, 33.946 pages/second > > that's quite decent i guess I certainly don't complain! CPU: 11th Gen Intel(R) Core(TM) i7-11700 @ 2.50GHz (2496.00-MHz K8-class CPU) FreeBSD/SMP: Multiprocessor System Detected: 16 CPUs FreeBSD/SMP: 1 package(s) x 8 core(s) x 2 hardware threads ZFS file system, pooled. (system on 2 mirrored SSDs and user files on 3 mirrored HDDs) > > system | total runtime: 68.547 seconds of 68.576 seconds > the fact that we have multiple runs make any optimization count for > more than on a single run Yes, absolutely! :-) Alan ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-16 20:02 ` bottlenecks Hans Hagen via ntg-context 2022-12-16 21:08 ` bottlenecks Rik Kabel via ntg-context @ 2022-12-17 16:02 ` Henning Hraban Ramm via ntg-context 2022-12-17 17:43 ` bottlenecks Hans Hagen via ntg-context 1 sibling, 1 reply; 19+ messages in thread From: Henning Hraban Ramm via ntg-context @ 2022-12-17 16:02 UTC (permalink / raw) To: ntg-context; +Cc: Henning Hraban Ramm Am 16.12.22 um 21:02 schrieb Hans Hagen via ntg-context: >> (2) >> This is a 720 page novel (first run with this LMTX version, some fonts >> were still uncached): >> > >> mkiv lua stats > runtime: 19.275 seconds, 720 processed pages, 720 >> shipped pages, 37.355 pages/second > so what if you add to the top > > \enableexperiments[fonts.compact] ok, updated to latest LMTX, first run, all fonts still uncached: mkiv lua stats > runtime: 19.025 seconds, 720 processed pages, 720 shipped pages, 37.846 pages/second system | total runtime: 73.873 seconds of 73.964 seconds real 1m13,971s user 1m10,581s sys 0m2,312s next run, with fonts.compact: mkiv lua stats > runtime: 19.327 seconds, 720 processed pages, 720 shipped pages, 37.254 pages/second system | total runtime: 19.353 seconds of 19.453 seconds real 0m19,461s user 0m18,966s sys 0m0,386s without fonts.compact: mkiv lua stats > runtime: 19.252 seconds, 720 processed pages, 720 shipped pages, 37.398 pages/second system | total runtime: 19.283 seconds of 19.379 seconds real 0m19,385s user 0m18,943s sys 0m0,380s minimal difference. 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-17 16:02 ` bottlenecks Henning Hraban Ramm via ntg-context @ 2022-12-17 17:43 ` Hans Hagen via ntg-context 0 siblings, 0 replies; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-17 17:43 UTC (permalink / raw) To: Henning Hraban Ramm via ntg-context; +Cc: Hans Hagen On 12/17/2022 5:02 PM, Henning Hraban Ramm via ntg-context wrote: > Am 16.12.22 um 21:02 schrieb Hans Hagen via ntg-context: >>> (2) >>> This is a 720 page novel (first run with this LMTX version, some >>> fonts were still uncached): >>> >> >>> mkiv lua stats > runtime: 19.275 seconds, 720 processed pages, 720 >>> shipped pages, 37.355 pages/second >> so what if you add to the top >> >> \enableexperiments[fonts.compact] > > ok, updated to latest LMTX, first run, all fonts still uncached: > > mkiv lua stats > runtime: 19.025 seconds, 720 processed pages, 720 > shipped pages, 37.846 pages/second > system | total runtime: 73.873 seconds of 73.964 seconds > > real 1m13,971s > user 1m10,581s > sys 0m2,312s > > next run, with fonts.compact: > > mkiv lua stats > runtime: 19.327 seconds, 720 processed pages, 720 > shipped pages, 37.254 pages/second > system | total runtime: 19.353 seconds of 19.453 seconds > > real 0m19,461s > user 0m18,966s > sys 0m0,386s > > without fonts.compact: > > mkiv lua stats > runtime: 19.252 seconds, 720 processed pages, 720 > shipped pages, 37.398 pages/second > system | total runtime: 19.283 seconds of 19.379 seconds > > > real 0m19,385s > user 0m18,943s > sys 0m0,380s > > minimal difference. the differences are mostly in loading times (say 10 times some cjk font or math font) the best way to check if compact mode was active is to check if the number of font instances changed for the record: compact mode actually has more overhead in the engine but it is compensated by other aspects of it Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-16 17:10 bottlenecks Hans Hagen via ntg-context 2022-12-16 19:36 ` bottlenecks Henning Hraban Ramm via ntg-context @ 2022-12-18 13:14 ` mf via ntg-context 2022-12-18 13:19 ` bottlenecks mf via ntg-context 2022-12-18 13:49 ` bottlenecks Hans Hagen via ntg-context 1 sibling, 2 replies; 19+ messages in thread From: mf via ntg-context @ 2022-12-18 13:14 UTC (permalink / raw) To: ntg-context; +Cc: mf latest ConTeXt 2022.12.15 18:12: mkiv lua stats > resource resolver: loadtime 0.009 seconds, 0 scans with scantime 0.000 seconds, 0 shared scans, 107 found files, scanned paths: <none> mkiv lua stats > stored bytecode data: 507 modules (0.346 sec), 106 tables (0.023 sec), 613 chunks (0.369 sec) mkiv lua stats > traced context: maxstack: 1923, freed: 246, unreachable: 1677 mkiv lua stats > cleaned up reserved nodes: 76 nodes, 9 lists of 504 mkiv lua stats > node memory usage: 1684 attribute, 419 glue, 87 gluespec, 3 kern, 647 mathspec, 4 penalty, 2 temp, 591 whatsit mkiv lua stats > node list callback tasks: 13 unique task lists, 17 instances (re)created, 325602 calls mkiv lua stats > h-node processing time: 10.442 seconds including kernel mkiv lua stats > attribute processing time: 2.783 seconds front- and backend mkiv lua stats > driver time: 11.187 seconds mkiv lua stats > used backend: pdf mkiv lua stats > jobdata time: 0.747 seconds saving, 0.195 seconds loading mkiv lua stats > callbacks: file: 5438, saved: 644352, direct: 1374, function: 540269, value: 1027, message: 0, bytecode: 613, late 0, total: 1193073 (1163 per page) mkiv lua stats > randomizer: resumed with value 0.58701179146283 mkiv lua stats > v-node processing time: 1.955 seconds mkiv lua stats > loaded patterns: en::1 it::66, load time: 0.000 mkiv lua stats > xml load time: 0.416 seconds, 1 files, 1 converted mkiv lua stats > lxml preparation time: 29.478 seconds, 47936 nodes, 24702 lpath calls, 24331 cached calls mkiv lua stats > interactive elements: 9336 references, 12951 destinations mkiv lua stats > margin data: 6 entries, 0 pending mkiv lua stats > loaded fonts: 27 files: lmmono10-regular.otf, texgyrepagella-math.otf, dejavusansmono.ttf, gfsneohellenic.otf, firasans-bolditalic.otf, firasans-regular.otf, firasans-regularitalic.otf, firasanscondensed-bold.otf, firasanscondensed-regular.otf, garamondpremrpro-bdit.otf, garamondpremrpro-med.otf, garamondpremrpro-medcapt.otf, garamondpremrpro-meddisp.otf, garamondpremrpro-medit.otf, garamondpremrpro-meditcapt.otf, garamondpremrpro-medsubh.otf, garamondpremrpro-smbdit.otf, myriadpro-bold.otf, myriadpro-boldcond.otf, myriadpro-boldcondit.otf, myriadpro-cond.otf, myriadpro-condit.otf, myriadpro-it.otf, myriadpro-regular.otf, myriadpro-semiboldit.otf, quivira.otf, sileot.ttf mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 533 instances, 501 shared in backend, 6 common vectors, 495 common hashes, load time 0.196 seconds mkiv lua stats > text directions: 5.754 seconds mkiv lua stats > metapost: 1.182 seconds, loading: 0.129, execution: 1.112, n: 1033, average: 0.002, instances: 2, luacalls: 46777 (file: 34671, text: 0, script: 5902, log: 6204), memory: 8.992 M mkiv lua stats > math tweaking time: 5.640 seconds, 126 math goodie tables mkiv lua stats > math processing time: 0.251 seconds mkiv lua stats > pdf annotations: 9336 links (9326 unique), 0 special mkiv lua stats > font embedding time: 0.049 seconds, 23 fonts mkiv lua stats > result saved in file: v32.pdf, compresslevel 0, objectcompresslevel 0 mkiv lua stats > positions: 8563 collected, 4775 deltas, 8556 shared partials, 304 partial entries mkiv lua stats > used platform: linux-64, type: unix, binary subtree: texmf-linux-64 mkiv lua stats > used engine: luametatex version: 2.1004, functionality level: 20221214, format id: 679, compiler: gcc mkiv lua stats > tex properties: 740852 hash slots used of 2097152, 94301 control sequences, approximate memory usage: 385 MB mkiv lua stats > lua properties: engine: lua 5.4, used memory: 1527 MB, ctx: 1436 MB, max: 1585 MB, symbol mask: utf (τεχ) mkiv lua stats > runtime: 130.080 seconds, 1026 processed pages, 1026 shipped pages, 7.887 pages/second system | total runtime: 130.269 seconds of 130.342 seconds ConTeXt 2020-04-22: mkiv lua stats > resource resolver: loadtime 0.005 seconds, 0 scans with scantime 0.000 seconds, 0 shared scans, 124 found files, scanned paths: <none> mkiv lua stats > stored bytecode data: 468 modules (0.349 sec), 93 tables (0.030 sec), 561 chunks (0.378 sec) mkiv lua stats > traced context: maxstack: 2799, freed: 246, unreachable: 2553 mkiv lua stats > cleaned up reserved nodes: 61 nodes, 11 lists of 512 mkiv lua stats > node memory usage: 200320 attribute, 23928 attribute_list, 419 glue, 368 glue_spec, 27234 glyph, 3 kern, 4 penalty, 2 temp, 1159 whatsit mkiv lua stats > node list callback tasks: 8 unique task lists, 14 instances (re)created, 236679 calls mkiv lua stats > h-node processing time: 13.188 seconds including kernel mkiv lua stats > attribute processing time: 5.444 seconds front- and backend mkiv lua stats > driver time: 12.650 seconds mkiv lua stats > used backend: lmtx version 0.10, pdf (backend for directly generating pdf output) mkiv lua stats > jobdata time: 2.286 seconds saving, 0.297 seconds loading mkiv lua stats > callbacks: internal: 459543, file: 5460, direct: 1378, late: 43406, function 385647, total: 895434 (874 per page) mkiv lua stats > randomizer: resumed with value 0.82926489398643 mkiv lua stats > positions: 7524 collected, 7523 regular, 1 special mkiv lua stats > v-node processing time: 1.286 seconds mkiv lua stats > result saved in file: v32.pdf, compresslevel 0, objectcompresslevel 0 mkiv lua stats > loaded patterns: en::1 it::58, load time: 0.000 mkiv lua stats > xml load time: 0.492 seconds, 1 files, 1 converted mkiv lua stats > lxml preparation time: 35.376 seconds, 47936 nodes, 25828 lpath calls, 25456 cached calls mkiv lua stats > interactive elements: 9343 references, 12951 destinations mkiv lua stats > margin data: 6 entries, 0 pending mkiv lua stats > loaded fonts: 26 files: lmmono10-regular.otf, texgyrepagella-math.otf, dejavusansmono.ttf, firasans-bolditalic.otf, firasans-regular.otf, firasans-regularitalic.otf, firasanscondensed-bold.otf, firasanscondensed-regular.otf, garamondpremrpro-bdit.otf, garamondpremrpro-med.otf, garamondpremrpro-medcapt.otf, garamondpremrpro-meddisp.otf, garamondpremrpro-medit.otf, garamondpremrpro-meditcapt.otf, garamondpremrpro-medsubh.otf, garamondpremrpro-smbdit.otf, myriadpro-bold.otf, myriadpro-boldcond.otf, myriadpro-boldcondit.otf, myriadpro-cond.otf, myriadpro-condit.otf, myriadpro-it.otf, myriadpro-regular.otf, myriadpro-semiboldit.otf, quivira.otf, sileot.ttf mkiv lua stats > font engine: otf 3.111, afm 1.513, tfm 1.000, 652 instances, 622 shared in backend, 6 common vectors, 616 common hashes, load time 20.311 seconds mkiv lua stats > text directions: 7.546 seconds mkiv lua stats > metapost: 1.819 seconds, loading: 0.096, execution: 1.724, n: 1033, average: 0.004, instances: 2, luacalls: 6628, memory: 8.935 M mkiv lua stats > math processing time: 0.224 seconds mkiv lua stats > pdf annotations: 9343 links (9341 unique), 0 special mkiv lua stats > font embedding time: 3.129 seconds, 23 fonts mkiv lua stats > used platform: linux-64, type: unix, binary subtree: texmf-linux-64 mkiv lua stats > used engine: luametatex version: 2.0502, functionality level: 20200413, format id: 493, compiler: gcc mkiv lua stats > control sequences: 91659 of 65536 + 100000 mkiv lua stats > lua properties: engine: lua 5.4, used memory: 1439 MB, ctx: 1374 MB, max: 1517 MB, hash chars: min(64,40), symbol mask: utf (τεχ) mkiv lua stats > runtime: 172.721 seconds, 1026 processed pages, 1026 shipped pages, 5.940 pages/second ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-18 13:14 ` bottlenecks mf via ntg-context @ 2022-12-18 13:19 ` mf via ntg-context 2022-12-18 13:49 ` bottlenecks Hans Hagen via ntg-context 1 sibling, 0 replies; 19+ messages in thread From: mf via ntg-context @ 2022-12-18 13:19 UTC (permalink / raw) To: ntg-context; +Cc: mf The old version is 2020.04.26 19:53, not 2020-04-22 ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-18 13:14 ` bottlenecks mf via ntg-context 2022-12-18 13:19 ` bottlenecks mf via ntg-context @ 2022-12-18 13:49 ` Hans Hagen via ntg-context 2022-12-18 15:21 ` bottlenecks mf via ntg-context 1 sibling, 1 reply; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-18 13:49 UTC (permalink / raw) To: mf via ntg-context; +Cc: Hans Hagen On 12/18/2022 2:14 PM, mf via ntg-context wrote: > ... So we gained a lot in the meantime. > mkiv lua stats > loaded fonts: 27 files: lmmono10-regular.otf, > texgyrepagella-math.otf, dejavusansmono.ttf, gfsneohellenic.otf, > firasans-bolditalic.otf, firasans-regular.otf, > firasans-regularitalic.otf, firasanscondensed-bold.otf, > firasanscondensed-regular.otf, garamondpremrpro-bdit.otf, > garamondpremrpro-med.otf, garamondpremrpro-medcapt.otf, > garamondpremrpro-meddisp.otf, garamondpremrpro-medit.otf, > garamondpremrpro-meditcapt.otf, garamondpremrpro-medsubh.otf, > garamondpremrpro-smbdit.otf, myriadpro-bold.otf, myriadpro-boldcond.otf, > myriadpro-boldcondit.otf, myriadpro-cond.otf, myriadpro-condit.otf, > myriadpro-it.otf, myriadpro-regular.otf, myriadpro-semiboldit.otf, > quivira.otf, sileot.ttf > mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 533 > instances, 501 shared in backend, 6 common vectors, 495 common hashes, > load time 0.196 seconds How does that report with compact font mode? Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-18 13:49 ` bottlenecks Hans Hagen via ntg-context @ 2022-12-18 15:21 ` mf via ntg-context 2022-12-18 15:27 ` bottlenecks Hans Hagen via ntg-context 0 siblings, 1 reply; 19+ messages in thread From: mf via ntg-context @ 2022-12-18 15:21 UTC (permalink / raw) To: ntg-context; +Cc: mf Il 18/12/22 14:49, Hans Hagen via ntg-context ha scritto: > On 12/18/2022 2:14 PM, mf via ntg-context wrote: > > > ... > > So we gained a lot in the meantime. > >> mkiv lua stats > loaded fonts: 27 files: lmmono10-regular.otf, >> texgyrepagella-math.otf, dejavusansmono.ttf, gfsneohellenic.otf, >> firasans-bolditalic.otf, firasans-regular.otf, >> firasans-regularitalic.otf, firasanscondensed-bold.otf, >> firasanscondensed-regular.otf, garamondpremrpro-bdit.otf, >> garamondpremrpro-med.otf, garamondpremrpro-medcapt.otf, >> garamondpremrpro-meddisp.otf, garamondpremrpro-medit.otf, >> garamondpremrpro-meditcapt.otf, garamondpremrpro-medsubh.otf, >> garamondpremrpro-smbdit.otf, myriadpro-bold.otf, >> myriadpro-boldcond.otf, myriadpro-boldcondit.otf, myriadpro-cond.otf, >> myriadpro-condit.otf, myriadpro-it.otf, myriadpro-regular.otf, >> myriadpro-semiboldit.otf, quivira.otf, sileot.ttf >> mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 533 >> instances, 501 shared in backend, 6 common vectors, 495 common >> hashes, load time 0.196 seconds > How does that report with compact font mode? > > mkiv lua stats > resource resolver: loadtime 0.005 seconds, 0 scans with scantime 0.000 seconds, 0 shared scans, 107 found files, scanned paths: <none> mkiv lua stats > stored bytecode data: 507 modules (0.285 sec), 106 tables (0.017 sec), 613 chunks (0.302 sec) mkiv lua stats > traced context: maxstack: 1923, freed: 246, unreachable: 1677 mkiv lua stats > cleaned up reserved nodes: 76 nodes, 9 lists of 504 mkiv lua stats > node memory usage: 1684 attribute, 110 fontspec, 419 glue, 87 gluespec, 3 kern, 647 mathspec, 4 penalty, 2 temp, 591 whatsit mkiv lua stats > node list callback tasks: 13 unique task lists, 17 instances (re)created, 325895 calls mkiv lua stats > h-node processing time: 10.654 seconds including kernel mkiv lua stats > attribute processing time: 2.810 seconds front- and backend mkiv lua stats > driver time: 11.714 seconds mkiv lua stats > used backend: pdf mkiv lua stats > jobdata time: 0.810 seconds saving, 0.194 seconds loading mkiv lua stats > callbacks: file: 5439, saved: 644924, direct: 1386, function: 534140, value: 1033, message: 0, bytecode: 613, late 0, total: 1187535 (1151 per page) mkiv lua stats > randomizer: resumed with value 0.58701179146283 mkiv lua stats > v-node processing time: 1.480 seconds mkiv lua stats > loaded patterns: en::1 it::66, load time: 0.000 mkiv lua stats > xml load time: 0.444 seconds, 1 files, 1 converted mkiv lua stats > lxml preparation time: 26.359 seconds, 47936 nodes, 24702 lpath calls, 24331 cached calls mkiv lua stats > interactive elements: 9327 references, 12951 destinations mkiv lua stats > margin data: 6 entries, 0 pending mkiv lua stats > loaded fonts: 27 files: lmmono10-regular.otf, texgyrepagella-math.otf, dejavusansmono.ttf, gfsneohellenic.otf, firasans-bolditalic.otf, firasans-regular.otf, firasans-regularitalic.otf, firasanscondensed-bold.otf, firasanscondensed-regular.otf, garamondpremrpro-bdit.otf, garamondpremrpro-med.otf, garamondpremrpro-medcapt.otf, garamondpremrpro-meddisp.otf, garamondpremrpro-medit.otf, garamondpremrpro-meditcapt.otf, garamondpremrpro-medsubh.otf, garamondpremrpro-smbdit.otf, myriadpro-bold.otf, myriadpro-boldcond.otf, myriadpro-boldcondit.otf, myriadpro-cond.otf, myriadpro-condit.otf, myriadpro-it.otf, myriadpro-regular.otf, myriadpro-semiboldit.otf, quivira.otf, sileot.ttf mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 46 instances, 16 shared in backend, 4 common vectors, 12 common hashes, load time 0.148 seconds mkiv lua stats > text directions: 5.911 seconds mkiv lua stats > metapost: 1.180 seconds, loading: 0.083, execution: 1.109, n: 1039, average: 0.002, instances: 2, luacalls: 46885 (file: 34713, text: 0, script: 5932, log: 6240), memory: 8.995 M mkiv lua stats > math tweaking time: 0.462 seconds, 8 math goodie tables mkiv lua stats > math processing time: 0.211 seconds mkiv lua stats > pdf annotations: 9327 links (9316 unique), 0 special mkiv lua stats > font embedding time: 0.104 seconds, 23 fonts mkiv lua stats > result saved in file: v32.pdf, compresslevel 0, objectcompresslevel 0 mkiv lua stats > positions: 8572 collected, 4774 deltas, 8565 shared partials, 305 partial entries mkiv lua stats > used platform: linux-64, type: unix, binary subtree: texmf-linux-64 mkiv lua stats > used engine: luametatex version: 2.1004, functionality level: 20221214, format id: 679, compiler: gcc mkiv lua stats > tex properties: 740852 hash slots used of 2097152, 93821 control sequences, approximate memory usage: 65 MB mkiv lua stats > lua properties: engine: lua 5.4, used memory: 338 MB, ctx: 266 MB, max: 415 MB, symbol mask: utf (τεχ) mkiv lua stats > runtime: 114.917 seconds, 1032 processed pages, 1032 shipped pages, 8.980 pages/second It's better, but the pages are 1032 against 1026. It means that some lines at the end of a page slip in the following pages. Since there are forced page breaks and chapters starting at odd pages, they are minimal differences that result in pages with only 1 or 2 lines of text, or white even pages. I don't know whether this is expected as the effect of \enableexperiments[fonts.compact] only. I expected a difference between version 2020-04-26 and the latest one, because it always happened when I tested the newest versions, though there has been a convergence of the resulting pdf and the differences are minimal now (between version 2020-04-26 and 2022-12-15). But it did not happen, the resulting pages are still 1026. Here's the results in short: ConTeXt 2020-04-26: runtime: 172.721 seconds, 1026 processed pages, 1026 shipped pages, 5.940 pages/second ConTeXt 2022-12-15: runtime: 130.080 seconds, 1026 processed pages, 1026 shipped pages, 7.887 pages/second ConTeXt 2022-12-15 with \enableexperiments[fonts.compact]: runtime: 114.917 seconds, 1032 processed pages, 1032 shipped pages, 8.980 pages/second Massi ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: bottlenecks 2022-12-18 15:21 ` bottlenecks mf via ntg-context @ 2022-12-18 15:27 ` Hans Hagen via ntg-context 0 siblings, 0 replies; 19+ messages in thread From: Hans Hagen via ntg-context @ 2022-12-18 15:27 UTC (permalink / raw) To: ntg-context; +Cc: Hans Hagen On 12/18/2022 4:21 PM, mf via ntg-context wrote: > Il 18/12/22 14:49, Hans Hagen via ntg-context ha scritto: >> On 12/18/2022 2:14 PM, mf via ntg-context wrote: >> >> > ... >> >> So we gained a lot in the meantime. >> >>> mkiv lua stats > loaded fonts: 27 files: lmmono10-regular.otf, >>> texgyrepagella-math.otf, dejavusansmono.ttf, gfsneohellenic.otf, >>> firasans-bolditalic.otf, firasans-regular.otf, >>> firasans-regularitalic.otf, firasanscondensed-bold.otf, >>> firasanscondensed-regular.otf, garamondpremrpro-bdit.otf, >>> garamondpremrpro-med.otf, garamondpremrpro-medcapt.otf, >>> garamondpremrpro-meddisp.otf, garamondpremrpro-medit.otf, >>> garamondpremrpro-meditcapt.otf, garamondpremrpro-medsubh.otf, >>> garamondpremrpro-smbdit.otf, myriadpro-bold.otf, >>> myriadpro-boldcond.otf, myriadpro-boldcondit.otf, myriadpro-cond.otf, >>> myriadpro-condit.otf, myriadpro-it.otf, myriadpro-regular.otf, >>> myriadpro-semiboldit.otf, quivira.otf, sileot.ttf >>> mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 533 >>> instances, 501 shared in backend, 6 common vectors, 495 common >>> hashes, load time 0.196 seconds >> How does that report with compact font mode? >> >> > mkiv lua stats > resource resolver: loadtime 0.005 seconds, 0 scans > with scantime 0.000 seconds, 0 shared scans, 107 found files, scanned > paths: <none> > mkiv lua stats > stored bytecode data: 507 modules (0.285 sec), 106 > tables (0.017 sec), 613 chunks (0.302 sec) > mkiv lua stats > traced context: maxstack: 1923, freed: 246, > unreachable: 1677 > mkiv lua stats > cleaned up reserved nodes: 76 nodes, 9 lists of 504 > mkiv lua stats > node memory usage: 1684 attribute, 110 fontspec, 419 > glue, 87 gluespec, 3 kern, 647 mathspec, 4 penalty, 2 temp, 591 whatsit > mkiv lua stats > node list callback tasks: 13 unique task lists, 17 > instances (re)created, 325895 calls > mkiv lua stats > h-node processing time: 10.654 seconds including kernel > mkiv lua stats > attribute processing time: 2.810 seconds front- and > backend > mkiv lua stats > driver time: 11.714 seconds > mkiv lua stats > used backend: pdf > mkiv lua stats > jobdata time: 0.810 seconds saving, 0.194 seconds loading > mkiv lua stats > callbacks: file: 5439, saved: 644924, direct: 1386, > function: 534140, value: 1033, message: 0, bytecode: 613, late 0, total: > 1187535 (1151 per page) > mkiv lua stats > randomizer: resumed with value 0.58701179146283 > mkiv lua stats > v-node processing time: 1.480 seconds > mkiv lua stats > loaded patterns: en::1 it::66, load time: 0.000 > mkiv lua stats > xml load time: 0.444 seconds, 1 files, 1 converted > mkiv lua stats > lxml preparation time: 26.359 seconds, 47936 nodes, > 24702 lpath calls, 24331 cached calls > mkiv lua stats > interactive elements: 9327 references, 12951 destinations > mkiv lua stats > margin data: 6 entries, 0 pending > mkiv lua stats > loaded fonts: 27 files: lmmono10-regular.otf, > texgyrepagella-math.otf, dejavusansmono.ttf, gfsneohellenic.otf, > firasans-bolditalic.otf, firasans-regular.otf, > firasans-regularitalic.otf, firasanscondensed-bold.otf, > firasanscondensed-regular.otf, garamondpremrpro-bdit.otf, > garamondpremrpro-med.otf, garamondpremrpro-medcapt.otf, > garamondpremrpro-meddisp.otf, garamondpremrpro-medit.otf, > garamondpremrpro-meditcapt.otf, garamondpremrpro-medsubh.otf, > garamondpremrpro-smbdit.otf, myriadpro-bold.otf, myriadpro-boldcond.otf, > myriadpro-boldcondit.otf, myriadpro-cond.otf, myriadpro-condit.otf, > myriadpro-it.otf, myriadpro-regular.otf, myriadpro-semiboldit.otf, > quivira.otf, sileot.ttf > mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 46 > instances, 16 shared in backend, 4 common vectors, 12 common hashes, > load time 0.148 seconds > mkiv lua stats > text directions: 5.911 seconds > mkiv lua stats > metapost: 1.180 seconds, loading: 0.083, execution: > 1.109, n: 1039, average: 0.002, instances: 2, luacalls: 46885 (file: > 34713, text: 0, script: 5932, log: 6240), memory: 8.995 M > mkiv lua stats > math tweaking time: 0.462 seconds, 8 math goodie tables > mkiv lua stats > math processing time: 0.211 seconds > mkiv lua stats > pdf annotations: 9327 links (9316 unique), 0 special > mkiv lua stats > font embedding time: 0.104 seconds, 23 fonts > mkiv lua stats > result saved in file: v32.pdf, compresslevel 0, > objectcompresslevel 0 > mkiv lua stats > positions: 8572 collected, 4774 deltas, 8565 shared > partials, 305 partial entries > mkiv lua stats > used platform: linux-64, type: unix, binary subtree: > texmf-linux-64 > mkiv lua stats > used engine: luametatex version: 2.1004, functionality > level: 20221214, format id: 679, compiler: gcc > mkiv lua stats > tex properties: 740852 hash slots used of 2097152, > 93821 control sequences, approximate memory usage: 65 MB > mkiv lua stats > lua properties: engine: lua 5.4, used memory: 338 MB, > ctx: 266 MB, max: 415 MB, symbol mask: utf (τεχ) > mkiv lua stats > runtime: 114.917 seconds, 1032 processed pages, 1032 > shipped pages, 8.980 pages/second > > It's better, but the pages are 1032 against 1026. > > It means that some lines at the end of a page slip in the following > pages. Since there are forced page breaks and chapters starting at odd > pages, they are minimal differences that result in pages with only 1 or > 2 lines of text, or white even pages. > > I don't know whether this is expected as the effect of > \enableexperiments[fonts.compact] only. i has to do with sightly different accuracy as we scale on the fly ... (we are somewhat stuck to this tex scaling model where 1000 = 1.0 but maybe it's time to revision that > I expected a difference between version 2020-04-26 and the latest one, > because it always happened when I tested the newest versions, though > there has been a convergence of the resulting pdf and the differences > are minimal now (between version 2020-04-26 and 2022-12-15). But it did > not happen, the resulting pages are still 1026. most of this has to do with fonts .. we bumped the accuracy a bit recently (to cope better with radical line alignment in some radicals) > Here's the results in short: > > ConTeXt 2020-04-26: > > runtime: 172.721 seconds, 1026 processed pages, 1026 shipped pages, > 5.940 pages/second > > ConTeXt 2022-12-15: > > runtime: 130.080 seconds, 1026 processed pages, 1026 shipped pages, > 7.887 pages/second > > ConTeXt 2022-12-15 with \enableexperiments[fonts.compact]: > > runtime: 114.917 seconds, 1032 processed pages, 1032 shipped pages, > 8.980 pages/second ok, so in your case compact font mode helps ... you could enable it in cont-loc.mkxl (we might switch to that mode by default in the future) ) Hans ----------------------------------------------------------------- Hans Hagen | PRAGMA ADE Ridderstraat 27 | 8061 GH Hasselt | The Netherlands tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl ----------------------------------------------------------------- ___________________________________________________________________________________ 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 ___________________________________________________________________________________ ^ permalink raw reply [flat|nested] 19+ messages in thread
end of thread, other threads:[~2022-12-18 21:35 UTC | newest] Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2022-12-16 17:10 bottlenecks Hans Hagen via ntg-context 2022-12-16 19:36 ` bottlenecks Henning Hraban Ramm via ntg-context 2022-12-16 20:02 ` bottlenecks Hans Hagen via ntg-context 2022-12-16 21:08 ` bottlenecks Rik Kabel via ntg-context 2022-12-16 22:07 ` bottlenecks Hans Hagen via ntg-context 2022-12-17 0:05 ` bottlenecks Rik Kabel via ntg-context 2022-12-17 9:48 ` bottlenecks Hans Hagen via ntg-context 2022-12-17 15:05 ` bottlenecks Rik Kabel via ntg-context 2022-12-17 17:21 ` bottlenecks Hans Hagen via ntg-context 2022-12-17 21:11 ` bottlenecks Alan Braslau via ntg-context 2022-12-17 21:35 ` bottlenecks Hans Hagen via ntg-context 2022-12-18 21:35 ` bottlenecks Alan Braslau via ntg-context 2022-12-17 16:02 ` bottlenecks Henning Hraban Ramm via ntg-context 2022-12-17 17:43 ` bottlenecks Hans Hagen via ntg-context 2022-12-18 13:14 ` bottlenecks mf via ntg-context 2022-12-18 13:19 ` bottlenecks mf via ntg-context 2022-12-18 13:49 ` bottlenecks Hans Hagen via ntg-context 2022-12-18 15:21 ` bottlenecks mf via ntg-context 2022-12-18 15:27 ` bottlenecks Hans Hagen via ntg-context
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).