Re: [NTG-context] bottlenecks

2022-12-18 Thread Alan Braslau via ntg-context
On Sat, 17 Dec 2022 22:35:04 +0100
Hans Hagen via ntg-context  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
___


Re: [NTG-context] bottlenecks

2022-12-18 Thread Hans Hagen via ntg-context

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: 
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 

Re: [NTG-context] bottlenecks

2022-12-18 Thread mf via ntg-context

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: 
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 

Re: [NTG-context] bottlenecks

2022-12-18 Thread Hans Hagen via ntg-context

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
___


Re: [NTG-context] bottlenecks

2022-12-18 Thread mf via ntg-context

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
___


Re: [NTG-context] bottlenecks

2022-12-18 Thread mf via ntg-context

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: 


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: 
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: 

Re: [NTG-context] bottlenecks

2022-12-17 Thread Hans Hagen via ntg-context

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
___


Re: [NTG-context] bottlenecks

2022-12-17 Thread Alan Braslau via ntg-context
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: 
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
___


Re: [NTG-context] bottlenecks

2022-12-17 Thread Hans Hagen via ntg-context

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
___


Re: [NTG-context] bottlenecks

2022-12-17 Thread Hans Hagen via ntg-context

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 

Re: [NTG-context] bottlenecks

2022-12-17 Thread Henning Hraban Ramm via ntg-context

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

real1m13,971s
user1m10,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

real0m19,461s
user0m18,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


real0m19,385s
user0m18,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
___


Re: [NTG-context] bottlenecks

2022-12-17 Thread Rik Kabel via ntg-context


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 

Re: [NTG-context] bottlenecks

2022-12-17 Thread Hans Hagen via ntg-context

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 s0.138 % 0.609968531 s0.160 %  3674 # 
prerollreference


 0.420704300 s0.095 % 0.420702649 s0.110 % 2 # 
analyzeregister


0.425307400 s0.096 % 0.425299968 s0.111 % 9 # 
action   1358 
...MTX/tex/texmf-context/tex/context/base/mkxl/math-act.lmt


0.681407500 s0.154 % 0.681338138 s0.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
___


Re: [NTG-context] bottlenecks

2022-12-17 Thread Rik Kabel via ntg-context

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  > 

Re: [NTG-context] bottlenecks

2022-12-16 Thread Hans Hagen via ntg-context

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
___


Re: [NTG-context] bottlenecks

2022-12-16 Thread Rik Kabel via ntg-context

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 

Re: [NTG-context] bottlenecks

2022-12-16 Thread Hans Hagen via ntg-context

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
___


Re: [NTG-context] bottlenecks

2022-12-16 Thread Henning Hraban Ramm via ntg-context

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, 

[NTG-context] bottlenecks

2022-12-16 Thread Hans Hagen via ntg-context

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
___