[SOLVED] fontconfig 2.11.94 slows down programs startup

kokoko3k · 2016-03-04 08:43:59

On a not so powerfull ATOM 330 running at 2ghz, i've noticed that even the simplest gui application using qt4 or gtk2 toolkits (didn't test other) suffers from a high delay when starting up.
On this particular machine, i measured it to be around one second.

The following script measures the application startup time of the program "gtk-demo"

#!/bin/bash
ln -s /usr/bin/sleep /tmp/mysleep &>/dev/null
time /tmp/mysleep 999 &

gtk-demo &
while true ; do
    wmctrl -l|grep 'GTK+ Code Demos' &>/tmp/out
    if [ $? -eq 0 ] ; then
        killall mysleep &>/tmp/out
        break
    fi
    sleep 0.05
done
killall gtk-demo &>/tmp/out
unlink /tmp/mysleep

Test startup time with ultimate packages:

$ pacman -Q|grep 'fontconfig\|freetype2'
fontconfig-infinality-ultimate 2.11.1-30
freetype2-infinality-ultimate 2.6.2-4

$ /tmp/startuptime.sh
/tmp/startuptime.sh: riga 3:  4321 Terminato               /tmp/mysleep 999

real    0m1.149s
user    0m0.000s
sys     0m0.000s

Now with standard fontconfig and freetype:

$ pacman -Q|grep 'fontconfig\|freetype2'
fontconfig 2.11.1-2
freetype2 2.6.3-1

$ /tmp/startuptime.sh
/tmp/startuptime.sh: riga 3:  4508 Terminato               /tmp/mysleep 999

real    0m0.325s
user    0m0.000s
sys     0m0.000s

If i isolate fontconfig:

$ pacman -Q|grep 'fontconfig\|freetype2'
fontconfig 2.11.1-2
freetype2-infinality-ultimate 2.6.2-4

$ /tmp/startuptime.sh
/tmp/startuptime.sh: riga 3:  5692 Terminato               /tmp/mysleep 999

real    0m0.386s
user    0m0.000s
sys     0m0.000s

So it seems fontconfig is doing a lot of work with the ultimate patches.
This happens with regular user account, never-used user accounts and the root account too.
I've already tried to rebuild the font cache with fc-cache -f and ran it with root and regular user, without success...

i used strace to debug the issue (strace -f gtk-demo)
and created two files: out_slow and out_fast:

$ grep ^stat64 /tmp/out_slow|grep font|wc -l
4600

$ grep ^stat64 /tmp/out_fast|grep font|wc -l
47

In out_slow, you see, it seems to walk across all of the fonts and more:

grep ^stat64 /tmp/out_fast|grep font >/tmp/stat_fast.txt
http://pastebin.com/vBLXakzT

grep ^stat64 /tmp/out_slow|grep font >/tmp/stat_slow.txt
http://pastebin.com/f8KGrFGr

complete strace fast
http://pastebin.com/60RsQpy2

complete strace slow (had to split these because they were too big)
http://pastebin.com/fbXDFN2B
http://pastebin.com/We6SxwN0

I cant undesrtand if this is a bug or just the expected behaviour.
Any hint?

-EDIT-
By simply overriding the fontconfig shared library, the issue goes away.
The following is with fontconfig-ultimate installed, and i'm going to preload the standard arch fontconfig:

LD_PRELOAD=/tmp/usr/lib/libfontconfig.so /tmp/startuptime.sh 
/tmp/startuptime.sh: riga 3:  7602 Terminato               /tmp/mysleep 999

real    0m0.376s
user    0m0.000s
sys     0m0.003s

-EDIT-
On a much more powerfull i5 cpu, the difference is still there; i've about 0.1seconds difference in favour of vanilla fontconfig.

Last edited by kokoko3k (2016-04-11 20:40:51)

ooo · 2016-03-04 12:52:29

~~Did you try rebuilding fontconfig cache?~~

fc-cache -r

also did you flush disk caches between the tests?

I see you already reported this to bohoomil's github, which may be better idea as I don't think there are many fontconfig experts in these forums.

EDIT: I see you already tried fc-cache -f

Last edited by ooo (2016-03-04 12:58:09)

kokoko3k · 2016-03-04 13:00:40

Yes, i tried to clear kernel caches.
Hoping bohoomil will read the message here or on github repo.

kokoko3k · 2016-03-06 08:49:24

Seems "upstream" git is affected too.
2.11.1 is fine 2.11.94 is not; and depsite the package i installed is named:
infinality-bundle/fontconfig-infinality-ultimate 2.11.1-30
it is indeed based on the 2.11.94 git version.

kokoko3k · 2016-03-07 16:09:40

since the bug seems from upstream, i filed a bugreport:
https://bugs.freedesktop.org/show_bug.cgi?id=94427

Vain · 2016-03-29 17:42:49

This will probably affect a lot more people now since fontconfig-2.11.94-1 is in extra. For example, my dmenu starts really slow now. "time fc-list" went from ~30ms (with fontconfig-2.11.1-2) to ~200ms. And my CPU is an i7-3770.

I did a git bisect and found this to be the first bad commit: https://cgit.freedesktop.org/fontconfig … 281ec1453b. I'll add it to the upstream report. And some ideas on how to improve the situation (which turned out to be nonsense, probably, but it's a start ).

Last edited by Vain (2016-03-30 03:47:49)

letni69 · 2016-03-29 22:48:20

I am noticing significant slow-downs, for example when I start Atom it seriously takes forever to load the editor window (The menu works fine...). After a downgrade from cache the bug is gone.

kokoko3k · 2016-03-30 06:53:15

@Vain, since i dubt arch would patch fontconfig and you found the offending commit, would you mind to create an aur package with a patch to revert it?

Ropid · 2016-03-30 14:26:15

I use "fontconfig-infinality-ultimate" which is currently at version 2.11.94, so is using the same upstream version as the normal fontconfig package. When I do "time fc-list > /dev/null", this runs in 0.026s on my i5-3570k, so speeds are completely fine.

Could the slow-down for you guys be caused by one of the config files that you might have written yourself or that came with a font package, or one of the fonts?

ooo · 2016-03-30 14:28:19

@kokoko3k, you could just download the patch of the offending commit from cgit, and revert it in PKGBUILD with 'patch -R'

kokoko3k · 2016-03-30 14:33:43

thanks ooo, i'll try.
@Ropid:
nope, as i pointed out, simply overriding the shared library through LD_PRELOAD restores "fast" speed (see near the end of the opening post)

-EDIT-
Also check startup time of gtk-demo through the script i posted with the old and the new fontconfig.

Last edited by kokoko3k (2016-03-30 14:35:20)

Ropid · 2016-03-30 16:52:50

I downloaded the "fontconfig-2.11.94-1-x86_64.pkg.tar.xz" package and tried the .so file in it with that gtk-demo time script, and it runs like this for me:

$ md5sum /tmp/fontconfig/usr/lib/libfontconfig.so
37aa4bfb1a4e4dd01a855d280a851d17  /tmp/fontconfig/usr/lib/libfontconfig.so

$ LD_PRELOAD=/tmp/fontconfig/usr/lib/libfontconfig.so ./startuptime.sh 
./startuptime.sh: line 3: 20409 Terminated              /tmp/mysleep 999

real	0m0.112s
user	0m0.000s
sys	0m0.000s

$ for x in {1..10}; do LD_PRELOAD=/tmp/fontconfig/usr/lib/libfontconfig.so ./startuptime.sh; done |& grep ^real
real	0m0.112s
real	0m0.113s
real	0m0.121s
real	0m0.124s
real	0m0.123s
real	0m0.132s
real	0m0.116s
real	0m0.117s
real	0m0.126s
real	0m0.123s

Then I checked the md5sum of my normal libfontconfig.so, and it's actually the same as with the Arch package:

$ md5sum /usr/lib/libfontconfig.so
37aa4bfb1a4e4dd01a855d280a851d17  /usr/lib/libfontconfig.so

$ pacman -Qo /usr/lib/libfontconfig.so
/usr/lib/libfontconfig.so is owned by fontconfig-infinality-ultimate 2.11.94-1

The script without LD_PRELOAD also runs fine:

$ for x in {1..10}; do ./startuptime.sh; done |& grep ^real
real	0m0.111s
real	0m0.130s
real	0m0.133s
real	0m0.118s
real	0m0.128s
real	0m0.124s
real	0m0.126s
real	0m0.119s
real	0m0.132s
real	0m0.122s

I then got "fontconfig-2.11.1-2-x86_64.pkg.tar.xz" from seblu.net:

$ md5sum /tmp/fontconfig-2.11.1/usr/lib/libfontconfig.so
cb452fe3da6bec6d09ed2932be307675  /tmp/fontconfig-2.11.1/usr/lib/libfontconfig.so

The first time I tried the script with it, it ran like this:

$ LD_PRELOAD=/tmp/fontconfig-2.11.1/usr/lib/libfontconfig.so ./startuptime.sh
./startuptime.sh: line 3: 22392 Terminated              /tmp/mysleep 999

real	0m4.964s
user	0m0.000s
sys	0m0.000s

That was just the first time. It ran fine the second time and afterwards:

$ LD_PRELOAD=/tmp/fontconfig-2.11.1/usr/lib/libfontconfig.so ./startuptime.sh
./startuptime.sh: line 3: 22693 Terminated              /tmp/mysleep 999

real	0m0.109s
user	0m0.000s
sys	0m0.000s

$ for x in {1..10}; do LD_PRELOAD=/tmp/fontconfig-2.11.1/usr/lib/libfontconfig.so ./startuptime.sh; done |& grep ^real
real	0m0.110s
real	0m0.121s
real	0m0.115s
real	0m0.120s
real	0m0.120s
real	0m0.121s
real	0m0.118s
real	0m0.125s
real	0m0.117s
real	0m0.120s

Vain · 2016-03-30 18:41:57

kokoko3k wrote:

@Vain, since i dubt arch would patch fontconfig and you found the offending commit, would you mind to create an aur package with a patch to revert it?

You're trying to create your own PKGBUILD right now, don't you? If you're not successful, I can help you do that or write one for you. But I'd rather not start maintaining a patched version of fontconfig in AUR. I'd much rather work on getting this fixed upstream.

Ropid wrote:

When I do "time fc-list > /dev/null", this runs in 0.026s on my i5-3570k, so speeds are completely fine.

The run time of that call also depends on the number of fonts installed on your system. Or rather the number of font files. I have about 4000 files in /usr/share/fonts/100dpi and /usr/share/fonts/75dpi alone. IIUC, those fonts are not required, so maybe you don't have them installed?

edit:

$ fc-match -a |cut -d ":" -f 1|sort -u |wc -l
963

Last edited by Vain (2016-03-30 18:53:04)

kokoko3k · 2016-03-30 18:47:14

Doing an average out of your 10 tests, it seems new fontconfig is way faster for you:

2.11.1:  0.1379 
2.11.94: 0.1243 (-0.0136)

For me, on an (another one) i5-4590:

2.11.1:  0.1345 
2.11.94: 0.215 (+0.0805)

I'm out of ideas, how many fonts do you have installed?

# fc-match -a |cut -d ":" -f 1|sort -u |wc -l
449

-EDIT-
Too late. Vain answered first.

@Vain, i'm already mantaining a couple of aur packages, so i think i'll just ignore the fontconfig upgrade till upstream will take care of it.

Last edited by kokoko3k (2016-03-30 18:57:07)

Ropid · 2016-03-30 19:18:52

$ fc-match -a |cut -d ":" -f 1|sort -u |wc -l
1238

I have basically nothing in /usr/share/fonts/100dpi and 75dpi (no font files). I found out with "pacman -Fo usr/share/fonts/100dpi/" that those folders are created by xorg-fonts-alias or xorg-fonts-100dpi. I don't have that xorg-fonts-100dpi installed, only the alias package.

Last edited by Ropid (2016-03-30 19:24:37)

kokoko3k · 2016-03-31 10:19:14

Ropid wrote:

$ fc-match -a |cut -d ":" -f 1|sort -u |wc -l
1238
I have basically nothing in /usr/share/fonts/100dpi and 75dpi (no font files). I found out with "pacman -Fo usr/share/fonts/100dpi/" that those folders are created by xorg-fonts-alias or xorg-fonts-100dpi. I don't have that xorg-fonts-100dpi installed, only the alias package.

Ok, that's weird, after uninstalling xorg-fonts (75 and 100 dpi), i've similar results:

# fontconfig 2.11.1

> for x in {1..10}; do  /tmp/startuptime.sh; done |& grep ^real
real    0m0.120s
real    0m0.138s
real    0m0.121s
real    0m0.139s
real    0m0.134s
real    0m0.132s
real    0m0.124s
real    0m0.141s
real    0m0.145s
real    0m0.126s

# fontconfig 2.11.94


> for x in {1..10}; do  /tmp/startuptime.sh; done |& grep ^real
real    0m0.116s
real    0m0.131s
real    0m0.131s
real    0m0.132s
real    0m0.133s
real    0m0.133s
real    0m0.181s
real    0m0.125s
real    0m0.128s
real    0m0.225s

fontconfig 2.11.94 + xorg-fonts-100dpi and xorg-fonts-75dpi:

> for x in {1..10}; do  /tmp/startuptime.sh; done |& grep ^real
real    0m0.226s
real    0m0.224s
real    0m0.219s
real    0m0.247s
real    0m0.253s
real    0m0.235s
real    0m0.199s
real    0m0.232s
real    0m0.256s
real    0m0.236s

Last edited by kokoko3k (2016-03-31 10:21:19)

Vain · 2016-03-31 16:16:33

kokoko3k wrote:

Ok, that's weird, after uninstalling xorg-fonts (75 and 100 dpi), i've similar results:

How's that weird? The run time depends on the number of font files to iterate over. Of course, when I remove those packages, it's fast for me, too.

It's probably an okay-ish workaround, since those two packages contain only bitmap fonts which are hardly used these days. Indeed, I have to admit that I only use exactly one of the fonts: Helvetica. I love that one, though. I could try to install only that font, but meh ...

kokoko3k · 2016-03-31 19:02:38

You're right, i didn't think those two packages contain so many items!

# with:
# fc-match -a|cut -d " " -f 1 |sort -u|wc -l
1098

#without:
# fc-match -a|cut -d " " -f 1 |sort -u|wc -l
700

Last edited by kokoko3k (2016-03-31 19:04:15)

kokoko3k · 2016-04-06 14:59:08

It seems upstream reverted the bad commit, however i'm unable to compile right now:

make[1]: Entering directory '/tmp/fontconfig/doc'
make[1]: '.gitignore' is up to date.
make[1]: Leaving directory '/tmp/fontconfig/doc'
make  all-recursive
make[1]: Entering directory '/tmp/fontconfig'
Making all in fontconfig
make[2]: Entering directory '/tmp/fontconfig/fontconfig'
make[2]: Leaving directory '/tmp/fontconfig/fontconfig'
Making all in fc-blanks
make[2]: Entering directory '/tmp/fontconfig/fc-blanks'
  GEN      fcblanks.h
  File "./fc-blanks.py", line 50
    raise RuntimeError, "Unexpected escape code"
                      ^
SyntaxError: invalid syntax
Makefile:592: recipe for target 'fcblanks.h' failed
make[2]: *** [fcblanks.h] Error 1
make[2]: Leaving directory '/tmp/fontconfig/fc-blanks'
Makefile:578: recipe for target 'all-recursive' failed
make[1]: *** [all-recursive] Error 1
make[1]: Leaving directory '/tmp/fontconfig'
Makefile:462: recipe for target 'all' failed
make: *** [all] Error 2

eschwartz · 2016-04-06 16:45:29

Upstream also released a new version which is in [Testing] right now...

Vain · 2016-04-06 16:50:31

@kokoko3k: On Arch, you have to build fontconfig with "make PYTHON=/usr/bin/python2".

Last edited by Vain (2016-04-06 19:46:41)

Vain · 2016-04-11 19:20:43

fontconfig-2.11.95 left testing, problem's gone -- but all non-bitmap fonts look different now. *sigh* ... which is caused by the new "10-hinting-slight.conf" being active by default. I'll be putting this in my ~/.config/fontconfig/fonts.conf and I'm back to "normal":

<?xml version="1.0"?>
<!DOCTYPE fontconfig SYSTEM "fonts.dtd">
<fontconfig>
	<!-- Disable the effects of 10-hinting-slight.conf -->
	<match target="pattern">
		<edit name="hintstyle" mode="delete"><const>hintslight</const></edit>
	</match>
</fontconfig>

– edit: See the following post for a better version: https://bbs.archlinux.org/viewtopic.php … 1#p1619751

Last edited by Vain (2016-05-15 12:23:11)

R00KIE · 2016-04-11 22:33:49

I wonder if it can be considered a bug that /etc/fonts/conf.d/10-hinting-slight.conf is now symlinked to /etc/fonts/conf.avail/10-hinting-slight.conf. I suppose this should be something that the user chooses to do and not forced upon.

Removing/renaming the symlink also works.

Scimmia · 2016-04-11 23:37:57

it's an upstream choice, not a bug.

R00KIE · 2016-04-11 23:47:45

Scimmia wrote:

it's an upstream choice, not a bug.

That sucks as it seems it will break things for some (many?) people.

Arch Linux

#1 2016-03-04 08:43:59

[SOLVED] fontconfig 2.11.94 slows down programs startup

#2 2016-03-04 12:52:29

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#3 2016-03-04 13:00:40

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#4 2016-03-06 08:49:24

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#5 2016-03-07 16:09:40

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#6 2016-03-29 17:42:49

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#7 2016-03-29 22:48:20

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#8 2016-03-30 06:53:15

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#9 2016-03-30 14:26:15

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#10 2016-03-30 14:28:19

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#11 2016-03-30 14:33:43

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#12 2016-03-30 16:52:50

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#13 2016-03-30 18:41:57

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#14 2016-03-30 18:47:14

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#15 2016-03-30 19:18:52

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#16 2016-03-31 10:19:14

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#17 2016-03-31 16:16:33

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#18 2016-03-31 19:02:38

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#19 2016-04-06 14:59:08

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#20 2016-04-06 16:45:29

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#21 2016-04-06 16:50:31

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#22 2016-04-11 19:20:43

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#23 2016-04-11 22:33:49

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#24 2016-04-11 23:37:57

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

#25 2016-04-11 23:47:45

Re: [SOLVED] fontconfig 2.11.94 slows down programs startup

Board footer