Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ImageFont.getlength dramatically slower in some environments #6631

Closed
avalonv opened this issue Oct 1, 2022 · 7 comments · Fixed by #6633
Closed

ImageFont.getlength dramatically slower in some environments #6631

avalonv opened this issue Oct 1, 2022 · 7 comments · Fixed by #6633

Comments

@avalonv
Copy link

avalonv commented Oct 1, 2022

What did you do?

There's this script which reads some text and recursively wraps/scales a TrueType font to fit an image. I was porting it to Windows and noticed that it ran almost 3x faster than Linux on the same machine, which greatly hurt my sense of superiority as a penguin user.

Never profiled python code before but what I did was python -m cProfile -o quote_to_image.prof quote_to_image.py, and then checked the output with snakeviz. Unless I'm wildly mistaken about how this stuff works, there's a massive discrepancy in time spent on getlength calls, despite the number of calls being very similar, with Linux spending more than 3 minutes to handle methods that Windows handled in 30 seconds.

ncalls  tottime percall         cumtime percall         filename:lineno(function)
1482429	187.6	0.0001265	187.6	0.0001265	~:0(<method 'getlength' of 'Font' objects>) Linux
1485834	26.45	1.78e-05	26.45	1.78e-05	~:0(<method 'getlength' of 'Font' objects>) Windows

To isolate the issue a bit more I decided to profile a shorter script with only the function that does most of these calls, and interestingly, the discrepancy isn't anywhere as large. However, it's still very obviously there:

ncalls  tottime percall         cumtime percall         filename:lineno(function)
96726	16.64	0.000172	16.64	0.000172	~:0(<method 'getlength' of 'Font' objects>) Linux
96726	12.72	0.0001315	12.72	0.0001315	~:0(<method 'getlength' of 'Font' objects>) Windows

I was able to reproduce both tests on different dual-booting machines with different python/pillow versions, however I didn't bother to save the results cause dual-booting on a HDD sucks. If I'm an idiot and you need more information let me know.

What did you expect to happen?

Similar time spent ImageFont getlength method calls on both operating systems.

What actually happened?

Windows was faster, ranging from 500% to 25% (increases exponentially with the number of calls?)

What are your OS, Python and Pillow versions?

  • OS: Windows 10/Arch linux 5.19
  • Python: 3.10.7
  • Pillow: 9.2.0
@radarhere
Copy link
Member

I tested this out with quote_to_image.py 100 on GitHub Actions, and found that the Test part of the run took 5 minutes on Windows, but took a few seconds on Linux.

I considered that perhaps the Windows environment had some sort of emulation making it run slower, so I added in a comparison.py script to compare the speeds by counting to 100 million, but they're relatively similar.

So given that I've seen the opposite results to you, I don't think this is as simple as Windows vs Linux.

@avalonv
Copy link
Author

avalonv commented Oct 2, 2022

Huh that's super interesting! I'm not at all familiar with Github actions, is there a way you could profile how much time was spent on each call from there?

@avalonv
Copy link
Author

avalonv commented Oct 2, 2022

To reiterate, this is like my first time ever reading this genre of logs, but it seems like the cache on the Linux test is much bigger than the Windows one, could that mean something?
Linux
image
Windows
image

@radarhere radarhere changed the title ImageFont.getlength dramatically slower on Linux ImageFont.getlength dramatically slower in some environments Oct 2, 2022
@nulano
Copy link
Contributor

nulano commented Oct 2, 2022

The test run by @radarhere was with heap verification enabled on Windows. After disabling it, Windows is only about 2x slower than Ubuntu. I also added a call to PIL.features.pilinfo, which shows that Windows is using Raqm layout and Ubuntu is using basic layout. Given this fact, I think a factor of 2x slower is about exactly what I would expect.

I'd expect the opposite is true for @avalonv since Raqm is much more likely to be available by default on Linux systems than on Windows. However, the difference observed in your first test is larger than what I'd expect for a typical font with a line of English text. It could be that the resulting image is different due to more complex layout rules used by Raqm. What font are you using, and what is the text being measured? Edit: I think I found your font and text, but it's a massive list. It might be helpful if you could narrow it down a bit.

If you don't care about complex layout, you could use font = ImageFont.truetype(..., layout_engine=ImageFont.Layout.BASIC) to force basic layout, but note that it might give worse results for non-English text.

To reiterate, this is like my first time ever reading this genre of logs, but it seems like the cache on the Linux test is much bigger than the Windows one, could that mean something?

Different test environments cache different things, there is no way this is related.

@avalonv
Copy link
Author

avalonv commented Oct 2, 2022

which shows that Windows is using Raqm layout and Ubuntu is using basic layout. Given this fact, I think a factor of 2x slower is about exactly what I would expect.

yeaaaah, that seems to be the culprit here! After setting layout_engine to ImageFont.Layout.BASIC the total processing time on my Linux machine fell to 108s, ten seconds faster than Windows, and the callstack graph looks very similar to the Windows profile I did earlier:

Linux
Windows

I can check PIL.features.pilinfo for the sake of thoroughness, but I think it's safe to assume that my Windows environment is using Layout.BASIC and the discrepancy stems almost entirely from that.

Thanks a lot for finding it :D

@avalonv
Copy link
Author

avalonv commented Oct 2, 2022

As for this issue: it would be nice to better document the pros and cons of each layout engine in the ImageFont docs. I skimmed through it quite a few times while trying to solve this, and sure enough, Layout.BASIC is there, but it's not completely clear which one is the default, or why you might prefer Layout.BASIC for some reason (i.e. better performance in certain tasks).
image

If I'm getting this right, Raqm is the default if available, but that's not really explicit in its documentation, just that you can check if it's available.

@radarhere
Copy link
Member

I've created PR #6633 to improve the documentation, resolving this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants