Performance issue on v53 with large font

[leesei]

When I tried the fix on v53 for #1392, I found WeasyPrint spent much longer time on "Step 7 - Adding PDF metadata".
The issue is related to the font "Noto Sans CJK TC" I used so it is not reproducible on any system.
This maybe reproducible with a large font.

PC config:

• Intel Core i5-7500 Kabylake 3.4GHz
• Kingston Hyper-X Fury 4x8GB (KHX2400C15/8G) 2400MHz DDR4
• ADATA Premier Pro SP920SS 256GB
• Arch Linux
• Python 3.9.7

Repo to reproduce this issue: https://github.com/leesei/WeasyPrint_1392 (Updated)

Run as is to produce the issue

time ./codes2tickets.py -vvvvv -o . ./schools.json
Namespace(input='./schools.json', verbose=5, out='.')
4>  ./ABC School.pdf
too much 'hmtx' table data
fsSelection bits 7, 8 and 9 are only defined in OS/2 table version 4 and up: version 3
5>  ./ABC School.pdf

________________________________________________________
Executed in   62.49 secs    fish           external
   usr time   71.44 secs  909.00 micros   71.44 secs
   sys time    1.15 secs  161.00 micros    1.15 secs

Without "Noto Sans CJK TC"

On systems without the font, or commenting out ln 13 (font-family: "Noto Sans CJK TC";) in styles.css

time ./codes2tickets.py -vvvvv -o . ./schools.json
Namespace(input='./schools.json', verbose=5, out='.')
4>  ./ABC School.pdf
too much 'hmtx' table data
fsSelection bits 7, 8 and 9 are only defined in OS/2 table version 4 and up: version 3
5>  ./ABC School.pdf

________________________________________________________
Executed in   29.67 secs    fish           external
   usr time   48.26 secs  706.00 micros   48.26 secs
   sys time    1.48 secs  113.00 micros    1.48 secs

WeasyPrint 52.5

The output PDF size is doubled though.

time ./codes2tickets.py -vvvvv -o . ./schools.json
Namespace(input='./schools.json', verbose=5, out='.')
4>  ./ABC School.pdf
5>  ./ABC School.pdf

________________________________________________________
Executed in   19.33 secs    fish           external
   usr time   18.88 secs  779.00 micros   18.88 secs
   sys time    0.36 secs  136.00 micros    0.36 secs

[liZe]

Hello, and thanks for the report.

It’s true, WeasyPrint 53.x is slower when dealing with fonts. It’s because we use fonttools to remove unused characters from fonts, and it takes a lot of time compared to what Cairo did.

A "workaround" is to use the --optimize-size=none: you’ll get a faster rendering, but your PDF size will increase.

Real fixes would be:

• to write our own fonts in the PDF, instead of optimizing the original font with fonttools (probably needed for Fonts with variable weight don’t work #1454 too); or
• to improve fonttools’ subset to be faster.

[leesei]

I see. I located the related codes.
I conducted tests with and without optimize font, like this:

    doc.write_pdf(
        path.join(outpath, f"{code['school']}.pdf"),
        image_cache=image_cache,
        optimize_size=(),
    )

And then run pdfsizeopt on the output PDF:

pdfsizeopt.single --do-optimize-images=no --do-require-image-optimizers=no 'ABC School.pdf' opted.pdf

Note: this is on another PC so the time is shorter in general

53.3 Running with optimize font

'ABC School.pdf' 2.5M
opted.pdf 1.3M
total time 43.81s + 598.15ms

time ./codes2tickets.py -vvvvv -o . ./schools.json
Namespace(input='./schools.json', verbose=5, out='.')
4>  ./ABC School.pdf
5>  ./ABC School.pdf

________________________________________________________
Executed in   43.81 secs    fish           external
   usr time   46.37 secs  418.00 micros   46.37 secs
   sys time    0.55 secs  165.00 micros    0.55 secs

time pdfsizeopt.single --do-optimize-images=no --do-require-image-optimizers=no ABC\ School.pdf opted.pdf
info: This is pdfsizeopt ZIP rUNKNOWN size=69734.
info: prepending to PATH: /home/leesei/caravan/applications/bin
error: image optimizer not found on PATH: jbig2
error: image optimizer not found on PATH: sam2p
error: image optimizer not found on PATH: sam2p
info: loading PDF from: ABC School.pdf
info: loaded PDF of 2553754 bytes
info: separated to 424 objs + xref + trailer
info: parsed 424 objs
info: found 0 Type1 fonts loaded
info: found 0 Type1C fonts loaded
info: optimized 206 streams, kept 206 zip
info: eliminated 198 duplicate objs
info: compressed 0 streams, kept 0 of them uncompressed
info: saving PDF with 226 objs to: opt.pdf
info: generated object stream of 2035 bytes in 115 objects (5%)
info: generated 1307486 bytes (51%)

________________________________________________________
Executed in  598.15 millis    fish           external
   usr time  564.71 millis    0.00 micros  564.71 millis
   sys time   30.61 millis  437.00 micros   30.18 millis

53.3 Running without optimize font

'ABC School.pdf' 34M
opted.pdf 2.9M
total time 17.69s + 3.22s

Namespace(input='./schools.json', verbose=5, out='.')
4>  ./ABC School.pdf
5>  ./ABC School.pdf

________________________________________________________
Executed in   17.69 secs    fish           external
   usr time   20.76 secs  333.00 micros   20.76 secs
   sys time    0.51 secs    0.00 micros    0.51 secs

time pdfsizeopt.single --do-optimize-images=no --do-require-image-optimizers=no ABC\ School.pdf opted.pdf
info: This is pdfsizeopt ZIP rUNKNOWN size=69734.
info: prepending to PATH: /home/leesei/caravan/applications/bin
error: image optimizer not found on PATH: jbig2
error: image optimizer not found on PATH: sam2p
error: image optimizer not found on PATH: sam2p
info: loading PDF from: ABC School.pdf
info: loaded PDF of 35271718 bytes
info: separated to 424 objs + xref + trailer
info: parsed 424 objs
info: found 0 Type1 fonts loaded
info: found 0 Type1C fonts loaded
info: optimized 206 streams, kept 206 zip
info: eliminated 198 duplicate objs
info: compressed 0 streams, kept 0 of them uncompressed
info: saving PDF with 226 objs to: opted.pdf
info: generated object stream of 2035 bytes in 115 objects (5%)
info: generated 33998765 bytes (96%)

________________________________________________________
Executed in    3.22 secs    fish           external
   usr time    3.12 secs  421.00 micros    3.12 secs
   sys time    0.10 secs    0.00 micros    0.10 secs

52.5

'ABC School.pdf' 5.9M
opted.pdf 33M
total time 13.97s + 1.87s

time ./codes2tickets.py -vvvvv -o . ./schools.json
Namespace(input='./schools.json', verbose=5, out='.')
4>  ./ABC School.pdf
5>  ./ABC School.pdf

________________________________________________________
Executed in   13.97 secs    fish           external
   usr time   13.83 secs  350.00 micros   13.83 secs
   sys time    0.16 secs   97.00 micros    0.16 secs

time pdfsizeopt.single --do-optimize-images=no --do-require-image-optimizers=no ABC\ School.pdf opted.pdf
info: This is pdfsizeopt ZIP rUNKNOWN size=69734.
info: prepending to PATH: /home/leesei/caravan/applications/bin
error: image optimizer not found on PATH: jbig2
error: image optimizer not found on PATH: sam2p
error: image optimizer not found on PATH: sam2p
info: loading PDF from: ABC School.pdf
info: loaded PDF of 6091590 bytes
info: separated to 831 objs + xref + trailer
info: parsed 831 objs
info: eliminated 210 unused objs, depth=9
info: found 0 Type1 fonts loaded
info: found 2 Type1C fonts loaded
info: optimized 206 streams, kept 203 #orig, 3 zip
info: eliminated 396 duplicate objs
info: compressed 0 streams, kept 0 of them uncompressed
info: saving PDF with 225 objs to: opted.pdf
info: generated object stream of 2104 bytes in 114 objects (5%)
info: generated 3015801 bytes (50%)

________________________________________________________
Executed in    1.87 secs    fish           external
   usr time    1.86 secs  283.00 micros    1.86 secs
   sys time    0.01 secs   76.00 micros    0.01 secs

---

Findings

• File size of 53.3 with font optimization is the best (but can still be optimized by pdfsizeopt)
• File size of 53.3 without font optimization is the worse (regression upon 52.5)

[leesei]

Since I've quite a lot of tickets to generate PDF, I'm wondering if this works:

1. subset the font once (given that I know all the characters used)
2. use FontConfiguration to specify and load the subset font
   can I load font in current folder?
3. use optimize_size=() for faster generation

[liZe]

• File size of 53.3 with font optimization is the best (but can still be optimized by pdfsizeopt)

For sure, there’s a lot of work yet, but better performances and smaller PDFs are on the roadmap. 😉

• File size of 53.3 without font optimization is the worse (regression upon 52.5)

Fonts with 52.5 are always "optimized" (actually re-created with needed glyphs by Cairo, not optimized by fontTools). So, the real regression is the speed issue, not the file size.

Since I've quite a lot of tickets to generate PDF, I'm wondering if this works: […]

It would work, but … You have to add a @font-face rule (that’s the only way to load a font that’s not installed) with a font-family name different from the original name (to avoid #1073).

[liZe]

(And don’t use WOFF or WOFF2 fonts, it would be even slower.)

[aschmitz]

For what it's worth, I spent a little bit of time earlier this week profiling effectively this exact issue (py-spy + speedscope is excellent for this), and found that indeed the vast majority of the time was spent in FontTools' subsetting.

There was a bit of low-hanging fruit to pick off in speeding it up, and I've submitted fonttools/fonttools#2467 for that. With those minor (+7 lines, -5 lines) changes, my test document render went down from 41 seconds to 6 seconds. A quick look showed that there were still optimizations that could be made in FontTools' subsetting, but they're not as major, and (at first glance) not as easy.

It turns out that Harfbuzz also has a subsetter (hb-subset), which may well be faster, but it doesn't support variable weights if you wanted to try to close #1454 at the same time. 😞

[liZe]

For what it's worth, I spent a little bit of time earlier this week profiling effectively this exact issue (py-spy + speedscope is excellent for this), and found that indeed the vast majority of the time was spent in FontTools' subsetting.

Good to know. I’ve been using cProfile + gprof2dot for years, but py-spy looks quite appealing.

There was a bit of low-hanging fruit to pick off in speeding it up, and I've submitted fonttools/fonttools#2467 for that. With those minor (+7 lines, -5 lines) changes, my test document render went down from 41 seconds to 6 seconds.

👏

It turns out that Harfbuzz also has a subsetter (hb-subset), which may well be faster

How did I miss that? Thanks for the information, it would be better to avoid fontTools if possible (mainly because it comes with non-pure-Python dependencies, but also for speed).

but it doesn't support variable weights if you wanted to try to close #1454 at the same time.

Then we’ll have to create our own fonts for that. Cairo already does that using Pango, so that’s possible, but it’s not easy to find how. Harfbuzz provides an experimental API to retrieve outlines, but until it’s stable I suppose that it’s better to use FreeType instead.

[anthrotype]

it would be better to avoid fontTools if possible (mainly because it comes with non-pure-Python dependencies

technically fontTools doesn't have any required dependencies, only optional extras. Looks like you require fonttools[woff], which depends on brotli and zopfli. We maintain those as well, so do let us know if we are missing any platform/OS/python versions that you need among the published PyPI wheels.

[liZe]

technically fontTools doesn't have any required dependencies, only optional extras. Looks like you require fonttools[woff], which depends on brotli and zopfli. We maintain those as well, so do let us know if we are missing any platform/OS/python versions that you need among the published PyPI wheels.

That’s right, and thanks a lot for maintaining these packages!

Avoiding non-pure-Python is useful to avoid newcomers with compilation errors when new versions of Python are released, often because they don’t even have a compiler installed. We already have a large stack of non-Python dependencies (Pango, Harfbuzz, Fontconfig, Freetype…) + Pillow, we shouldn’t hesitate to remove some of them if it’s possible to have the same features with the other deps.

[anthrotype]

We do try to rebuild wheels as soon as new python versions reach stable. Anyway, for some things like compression pure python would be too slow so there's now way around native dependencies.
BTW, fonttools 4.28.4 is out with @aschmitz's patch to the subsetter. Thanks!

[liZe]

I’ve tried to use Harfbuzz’ subsetter instead of fontTools’ one, but I’m not sure that the results are worth the change. It’s pushed on the hb-subset branch, benchmarks and feedback are welcome!

(It looks like hb-subset is not installed everywhere with Harfbuzz, so it actually may just be another problem on top of our current problems…)

[aschmitz]

Thanks! I'll try to get a chance to test that out soon. With an eye towards v55's performance goals, I'd also like to automatically profile some of our document renders to get an idea of where the hotspots are at least for our documents, but it's likely to be [at least] several weeks before I get there.

[liZe]

Thanks! I'll try to get a chance to test that out soon.

👍

With an eye towards v55's performance goals, I'd also like to automatically profile some of our document renders to get an idea of where the hotspots are at least for our documents, but it's likely to be [at least] several weeks before I get there.

You could find WeasyPerf useful!

[liZe]

f8110d6 has been written to save a couple of seconds for tests, but it gives incredible results with documents with a lot of big fonts. Don’t hesitate to try!

[liZe]

Let’s say it’s fixed!