Anti-bloat side project

Anti-bloat side project

[Rich Felker]

One side effect of getting dynamic loading working, and being able to
test Perl and Python a bit, is that I've seen a ridiculous level of
inefficiency, especially in Python which is increasingly becoming a
required dependency for many components of a "complete Linux system".
As an example it takes Python nearly 600 syscalls just to run a hello
world program, compared to about 40 for perl or bash and 20 for ash
(and of course about 3 for musl-linked C using stdio). Much of this
was spent searching nonsensical pathnames for config files and shared
library modules. And let's not even get into the memory usage at this
point...

Anyway my idea for a side project to benefit the whole Linux community
(not just musl users) is to document and analyze the causes of startup
bloat/syscall bloat (which leads to bad performance, especially in
"script"-type programs that run many times) and memory bloat in some
core components that are used on most modern Linux-based systems:

- Python
- Perl
- Glib
- GTK
- ncurses
- etc.

and then sending reports (and possible fix ideas) to the upstream
maintainers. This is not something I plan to do myself (I'd rather
spend time improving musl) but I want to propose it as a way for
members of the community to contribute to positive anti-bloat work
that benefits a large number of users, as opposed to the alternative
of just boycotting software that "sucks" for bloat reasons. :-)

Rich

Re: Anti-bloat side project

[Szabolcs Nagy]

* Rich Felker <dalias@aerifal.cx> [2011-06-27 13:08:06 -0400]:
> As an example it takes Python nearly 600 syscalls just to run a hello
> world program, compared to about 40 for perl or bash and 20 for ash
> (and of course about 3 for musl-linked C using stdio). Much of this
> was spent searching nonsensical pathnames for config files and shared

i get different numbers on my (ubuntu) system

nsz@tpx:~$ strace python -c '' 2>&1 |wc -l
670
nsz@tpx:~$ strace perl -e '' 2>&1 |wc -l
176
nsz@tpx:~$ strace sh -c '' 2>&1 |wc -l
42
nsz@tpx:~$ strace bash -c '' 2>&1 |wc -l
186
nsz@tpx:~$ strace awk '' 2>&1 |wc -l
95
nsz@tpx:~$ strace mawk '' 2>&1 |wc -l
39
nsz@tpx:~$ strace lua -e '' 2>&1 |wc -l
67
nsz@tpx:~$ strace bc </dev/null 2>&1 |wc -l
60
nsz@tpx:~$ strace sed '' </dev/null 2>&1 |wc -l
110
nsz@tpx:~$ strace cat </dev/null 2>&1 |wc -l
111
nsz@tpx:~$ strace dd </dev/null 2>&1 |wc -l
162
nsz@tpx:~$ strace grep . </dev/null 2>&1 |wc -l
127
nsz@tpx:~$ strace /bin/true 2>&1 |wc -l
107

without locale crap

nsz@tpx:~$ export LC_ALL=C
nsz@tpx:~$ strace python -c '' 2>&1 |wc -l
652
nsz@tpx:~$ strace perl -e '' 2>&1 |wc -l
99
nsz@tpx:~$ strace sh -c '' 2>&1 |wc -l
42
nsz@tpx:~$ strace bash -c '' 2>&1 |wc -l
101
nsz@tpx:~$ strace awk '' 2>&1 |wc -l
55
nsz@tpx:~$ strace mawk '' 2>&1 |wc -l
39
nsz@tpx:~$ strace lua -e '' 2>&1 |wc -l
67
nsz@tpx:~$ strace bc </dev/null 2>&1 |wc -l
60
nsz@tpx:~$ strace sed '' </dev/null 2>&1 |wc -l
35
nsz@tpx:~$ strace cat </dev/null 2>&1 |wc -l
36
nsz@tpx:~$ strace dd </dev/null 2>&1 |wc -l
74
nsz@tpx:~$ strace grep . </dev/null 2>&1 |wc -l
40
nsz@tpx:~$ strace /bin/true 2>&1 |wc -l
32


> Anyway my idea for a side project to benefit the whole Linux community
> (not just musl users) is to document and analyze the causes of startup
> bloat/syscall bloat (which leads to bad performance, especially in
> "script"-type programs that run many times) and memory bloat in some
> core components that are used on most modern Linux-based systems:
> 
> - Python
> - Perl
> - Glib
> - GTK
> - ncurses
> - etc.
> 
> and then sending reports (and possible fix ideas) to the upstream
> maintainers. This is not something I plan to do myself (I'd rather
> spend time improving musl) but I want to propose it as a way for
> members of the community to contribute to positive anti-bloat work
> that benefits a large number of users, as opposed to the alternative
> of just boycotting software that "sucks" for bloat reasons. :-)

nice
imho these issues are well known, ppl just don't care enough

i remember when the first google summer of codes was announced
one of the first python project idea was to do something
about the number of syscalls at startup
http://wiki.python.org/moin/CodingProjectIdeas/PythonCore

it did not improve much since then, even in python3 ppl are
complaining about the syscalls but devs say it does not matter
http://mail.python.org/pipermail/python-dev/2011-January/107771.html
http://mail.python.org/pipermail/python-dev/2011-January/107789.html

Re: Anti-bloat side project

[Rich Felker]

On Mon, Jun 27, 2011 at 11:16:25PM +0200, Szabolcs Nagy wrote:
> * Rich Felker <dalias@aerifal.cx> [2011-06-27 13:08:06 -0400]:
> > As an example it takes Python nearly 600 syscalls just to run a hello
> > world program, compared to about 40 for perl or bash and 20 for ash
> > (and of course about 3 for musl-linked C using stdio). Much of this
> > was spent searching nonsensical pathnames for config files and shared
> 
> i get different numbers on my (ubuntu) system

Yes, I was measuring with musl... Thanks for the figures.

> > and then sending reports (and possible fix ideas) to the upstream
> > maintainers. This is not something I plan to do myself (I'd rather
> > spend time improving musl) but I want to propose it as a way for
> > members of the community to contribute to positive anti-bloat work
> > that benefits a large number of users, as opposed to the alternative
> > of just boycotting software that "sucks" for bloat reasons. :-)
> 
> nice
> imho these issues are well known, ppl just don't care enough
> 
> i remember when the first google summer of codes was announced
> one of the first python project idea was to do something
> about the number of syscalls at startup
> http://wiki.python.org/moin/CodingProjectIdeas/PythonCore
> 
> it did not improve much since then, even in python3 ppl are
> complaining about the syscalls but devs say it does not matter
> http://mail.python.org/pipermail/python-dev/2011-January/107771.html
> http://mail.python.org/pipermail/python-dev/2011-January/107789.html

Bleh. Has there been any serious work to document the causes and how
the code could be changed to fix the syscall bloat though? Or just
preliminat strace and wc -l?

Rich

Re: Anti-bloat side project

[Rich Felker]

On Mon, Jun 27, 2011 at 11:38:05PM +0200, Szabolcs Nagy wrote:
> * Rich Felker <dalias@aerifal.cx> [2011-06-27 17:19:09 -0400]:
> > Bleh. Has there been any serious work to document the causes and how
> > the code could be changed to fix the syscall bloat though? Or just
> > preliminat strace and wc -l?
> 
> most of the syscalls are due to python module imports check
> 100 different locations before finding the good one
> 
> imho they measured it and concluded that with modern
> filesystem caching this does not matter much..

Well they're wrong. Even if the syscall did nothing but enter and
leave kernelspace, it would still be very expensive. Using a module
cache/registry of some sort could solve the problem, or they could
first tackle all the non-open() syscalls which still make up a heavy
share of the cost..

Rich

Re: Anti-bloat side project

[Szabolcs Nagy]

* Rich Felker <dalias@aerifal.cx> [2011-06-27 17:19:09 -0400]:
> Bleh. Has there been any serious work to document the causes and how
> the code could be changed to fix the syscall bloat though? Or just
> preliminat strace and wc -l?

most of the syscalls are due to python module imports check
100 different locations before finding the good one

imho they measured it and concluded that with modern
filesystem caching this does not matter much..

Re: Anti-bloat side project

[Rich Felker]

On Mon, Jun 27, 2011 at 05:37:39PM -0400, Rich Felker wrote:
> On Mon, Jun 27, 2011 at 11:38:05PM +0200, Szabolcs Nagy wrote:
> > * Rich Felker <dalias@aerifal.cx> [2011-06-27 17:19:09 -0400]:
> > > Bleh. Has there been any serious work to document the causes and how
> > > the code could be changed to fix the syscall bloat though? Or just
> > > preliminat strace and wc -l?
> > 
> > most of the syscalls are due to python module imports check
> > 100 different locations before finding the good one
> > 
> > imho they measured it and concluded that with modern
> > filesystem caching this does not matter much..
> 
> Well they're wrong. Even if the syscall did nothing but enter and
> leave kernelspace, it would still be very expensive. Using a module
> cache/registry of some sort could solve the problem, or they could
> first tackle all the non-open() syscalls which still make up a heavy
> share of the cost..

Of course a better question is... why does "hello world" need to load
any modules anyway? Perhaps a best first step to fixing the problem
would be to demodularize and static link any module that will always
be loaded...

Rich

Re: Anti-bloat side project

[Szabolcs Nagy]

* Rich Felker <dalias@aerifal.cx> [2011-06-27 17:43:00 -0400]:
> Of course a better question is... why does "hello world" need to load
> any modules anyway? Perhaps a best first step to fixing the problem
> would be to demodularize and static link any module that will always
> be loaded...

btw applications are worse even if they are written in c

gtk hello:
$ strace zenity --info --text=hello 2>&1 |wc -l
6491

x terminal emulators:
$ strace xterm -e /bin/true 2>&1 |wc -l
1214
$ strace urxvt -e /bin/true 2>&1 |wc -l
850

firefox with a newly created empty profile
(no extensions, and blank page):
$ strace -f firefox -P empty -url about:blank 2>&1 |wc -l
17980

(ff has many periodic timers and does many things in the
background so the number depends on how fast i kill the
apearing window but it's always >16000)


$ strace -c -Scalls zenity --info --text=hello
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 13.70    0.000181           0      1510       417 stat64
  9.84    0.000130           0      1277       573 open
 59.95    0.000792           1       988           getdents64
  2.42    0.000032           0       706           close
  1.97    0.000026           0       672           fstat64
  2.42    0.000032           0       560        92 read
  2.95    0.000039           0       174           mmap2
  6.74    0.000089           1       157           select
  0.00    0.000000           0       101        68 access
  0.00    0.000000           0        80           writev
  0.00    0.000000           0        58           gettimeofday
  0.00    0.000000           0        55           mprotect
  0.00    0.000000           0        36           poll
  0.00    0.000000           0        19           munmap
  0.00    0.000000           0        17           brk
  0.00    0.000000           0         8           uname
  0.00    0.000000           0         6           fcntl64
  0.00    0.000000           0         4           _llseek
  0.00    0.000000           0         4           futex
...
100.00    0.001321                  6463      1153 total

$ strace -c -Scalls -f firefox -P empty -url about:blank
...
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.01    0.000104           0      2244      1010 close
  0.03    0.000355           0      2099       988 open
  0.01    0.000159           0      1924       520 stat64
  0.01    0.000093           0      1826           gettimeofday
  0.19    0.002521           2      1595       284 read
  0.00    0.000000           0      1112           fstat64
  0.03    0.000333           0       994           getdents64
  0.01    0.000160           0       662           mmap2
 64.14    0.849392        1361       624        26 futex
  0.01    0.000075           0       623         1 madvise
  0.00    0.000036           0       481           select
  0.00    0.000000           0       462       301 access
  0.01    0.000069           0       267           writev
  0.00    0.000000           0       228           fcntl64
  0.00    0.000000           0       213           mprotect
  0.00    0.000036           0       167           _llseek
  0.00    0.000000           0       160           clock_gettime
  0.00    0.000000           0       140           munmap
 16.92    0.224014        1882       119           poll
  0.00    0.000000           0        92         3 lstat64
  0.00    0.000000           0        53           write
  0.00    0.000000           0        52           rt_sigaction
  0.00    0.000000           0        51           lseek
  0.00    0.000000           0        46           brk
  0.00    0.000000           0        41           getdents
  0.00    0.000000           0        25           uname
  0.09    0.001185          59        20         4 execve
  0.24    0.003125         156        20           clone
  0.00    0.000000           0        19           pipe
  0.00    0.000000           0        18           socket
  0.00    0.000000           0        16           set_thread_area
  0.48    0.006364         424        15         2 wait4
  0.00    0.000000           0        15         7 connect
  0.00    0.000000           0        14           dup2
  0.00    0.000000           0        12           getuid32
  0.00    0.000000           0        11           geteuid32
  0.00    0.000000           0         9           time
  0.00    0.000000           0         8         1 readlink
  0.00    0.000000           0         8           sched_get_priority_max
  0.00    0.000000           0         8           getgroups32
  0.00    0.000000           0         7           sched_get_priority_min
  0.00    0.000000           0         7           set_robust_list
  0.00    0.000000           0         6           sched_setscheduler
  0.00    0.000000           0         5           getgid32
  0.00    0.000000           0         5           getegid32
  0.00    0.000000           0         4           getpid
  0.00    0.000000           0         4         4 mkdir
  0.00    0.000000           0         4           getppid
  0.00    0.000000           0         4           getsockname
...
100.00    1.324219                 16588      3153 total

Re: Anti-bloat side project

[Rich Felker]

On Wed, Jun 29, 2011 at 04:19:45PM +0200, Szabolcs Nagy wrote:
> * Rich Felker <dalias@aerifal.cx> [2011-06-27 17:43:00 -0400]:
> > Of course a better question is... why does "hello world" need to load
> > any modules anyway? Perhaps a best first step to fixing the problem
> > would be to demodularize and static link any module that will always
> > be loaded...
> 
> btw applications are worse even if they are written in c

Well we're now talking about applications which actually DO
something...

> gtk hello:
> $ strace zenity --info --text=hello 2>&1 |wc -l
> 6491

What about the gtk hello world from the gtk tutorial?

> x terminal emulators:
> $ strace xterm -e /bin/true 2>&1 |wc -l
> 1214
> $ strace urxvt -e /bin/true 2>&1 |wc -l
> 850

These numbers are not that bad... only about twice as much as Python
and doing A LOT more. By the way, uuterm is 525, so the vast majority
of that is xlib... (Of course then uuterm starts the evil blinking
cursor if you leave it sitting.. ;)

> $ strace -c -Scalls zenity --info --text=hello
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  13.70    0.000181           0      1510       417 stat64
>   9.84    0.000130           0      1277       573 open
>  59.95    0.000792           1       988           getdents64

Looks like it's performing a lot of scandir or glob...

> $ strace -c -Scalls -f firefox -P empty -url about:blank
> ....
>  64.14    0.849392        1361       624        26 futex

624 cases of lock contention during startup is pretty bad...

>   0.24    0.003125         156        20           clone

Of course 20 threads could contribute to that...

>   0.48    0.006364         424        15         2 wait4

And lots of child processes..?!

Rich

Re: Anti-bloat side project

[Szabolcs Nagy]

* Rich Felker <dalias@aerifal.cx> [2011-06-29 15:27:36 -0400]:
> On Wed, Jun 29, 2011 at 04:19:45PM +0200, Szabolcs Nagy wrote:
> > gtk hello:
> > $ strace zenity --info --text=hello 2>&1 |wc -l
> > 6491
> 
> What about the gtk hello world from the gtk tutorial?
> 

ok that's better, "only" 1400 syscalls
many of it is about dynamic linking, reading large config files
locale things and of course communicating with x

$ strace -c -Scalls ./t
Hello World
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 17.65    0.000099           0       321        78 read
  0.00    0.000000           0       219        82 open
  5.53    0.000031           0       160           mmap2
  0.00    0.000000           0       139           close
  0.00    0.000000           0       124         1 select
  0.00    0.000000           0       106           fstat64
  7.13    0.000040           0        93        60 access
  6.60    0.000037           1        64           writev
  0.00    0.000000           0        58         1 stat64
 63.10    0.000354           7        49           mprotect
  0.00    0.000000           0        27           poll
  0.00    0.000000           0        16           gettimeofday
  0.00    0.000000           0        16           munmap
  0.00    0.000000           0        10           brk
  0.00    0.000000           0         7           uname
  0.00    0.000000           0         6           fcntl64
  0.00    0.000000           0         3         1 lstat64
  0.00    0.000000           0         3           futex
  0.00    0.000000           0         3           socket
  0.00    0.000000           0         3         2 connect
...
100.00    0.000561                  1448       225 total

Re: Anti-bloat side project

[Moritz Wilhelmy]

Hello,

While debugging mlmmj, my mailing list manager of choice, I noted that
it calls read(2) really, really often, in order to read a single byte
out of a fd, and then read the next byte, like this:

open("/var/spool/mlmmj/foo/control/listaddress", O_RDONLY) = 4
read(4, "f", 1)                         = 1
read(4, "o", 1)                         = 1
read(4, "o", 1)                         = 1
read(4, "@", 1)                         = 1
read(4, "l", 1)                         = 1
read(4, "i", 1)                         = 1
read(4, "s", 1)                         = 1
read(4, "t", 1)                         = 1
read(4, "s", 1)                         = 1
read(4, ".", 1)                         = 1
read(4, "e", 1)                         = 1
read(4, "x", 1)                         = 1
read(4, "a", 1)                         = 1
read(4, "m", 1)                         = 1
read(4, "p", 1)                         = 1
read(4, "l", 1)                         = 1
read(4, "e", 1)                         = 1
read(4, ".", 1)                         = 1
read(4, "c", 1)                         = 1
read(4, "o", 1)                         = 1
read(4, "m", 1)                         = 1
read(4, "\n", 1)                        = 1
close(4)                                = 0

It does this for every file it touches as well as network connections it
reads from.
I don't know yet, how and why exactly it does it this way, but it seems
rather insane to me, so I think it might need some patches in order to
clean it up.

It turned out that attempting to subscribe someone to a mailing list
used 794 read(x, y, 1) style syscalls. I don't think I want to know how
often it calls read() in order to post a message to all members of the
list.
Maybe this could be solved by using getline(3) instead, which is in
POSIX.1-2008 and implemented on current versions of at least glibc,
FreeBSD, NetBSD and of course musl.
I will contact the mlmmj developers and try to resolve the issue.

Solar, maybe you should still wait a bit before switching openwall over
to mlmmj ;)

Best,
	Moritz

Re: Anti-bloat side project

[Rich Felker]

On Tue, Aug 16, 2011 at 03:03:50PM +0200, Moritz Wilhelmy wrote:
> Hello,
> 
> While debugging mlmmj, my mailing list manager of choice, I noted that
> it calls read(2) really, really often, in order to read a single byte
> out of a fd, and then read the next byte, like this:
> 
> open("/var/spool/mlmmj/foo/control/listaddress", O_RDONLY) = 4
> read(4, "f", 1)                         = 1
> read(4, "o", 1)                         = 1
> read(4, "o", 1)                         = 1
> read(4, "@", 1)                         = 1

Is it possibly implemented as a shell script? The way the shell "read"
command works, it's required to perform byte-at-a-time reads like
this. Otherwise, I'm guessing someone just foolishly turned off
buffering on the FILE...

Rich

Re: Anti-bloat side project

[Moritz Wilhelmy]

On Tue, Aug 16, 2011 at 09:06:43 -0400, Rich Felker wrote:
> Is it possibly implemented as a shell script? The way the shell "read"
> command works, it's required to perform byte-at-a-time reads like
> this. Otherwise, I'm guessing someone just foolishly turned off
> buffering on the FILE...

In fact, it really is a C program, and sadly, it seems they really
implement it that way (by greping over the code for about 30 seconds);

See src/mygetline.c on hg tip[1]:
 41         while(1) {
 42                 res = read(fd, &ch, 1);

Maybe coders need to be educated about how not to write code in order to
avoid (syscall-)bloat?

[1]: http://mlmmj.org/hg/mlmmj/file/tip/src/mygetline.c

	Moritz

Re: Anti-bloat side project

[Rich Felker]

On Tue, Aug 16, 2011 at 03:16:10PM +0200, Moritz Wilhelmy wrote:
> On Tue, Aug 16, 2011 at 09:06:43 -0400, Rich Felker wrote:
> > Is it possibly implemented as a shell script? The way the shell "read"
> > command works, it's required to perform byte-at-a-time reads like
> > this. Otherwise, I'm guessing someone just foolishly turned off
> > buffering on the FILE...
> 
> In fact, it really is a C program, and sadly, it seems they really
> implement it that way (by greping over the code for about 30 seconds);
> 
> See src/mygetline.c on hg tip[1]:
>  41         while(1) {
>  42                 res = read(fd, &ch, 1);
> 
> Maybe coders need to be educated about how not to write code in order to
> avoid (syscall-)bloat?
> 
> [1]: http://mlmmj.org/hg/mlmmj/file/tip/src/mygetline.c

As they're using a file descriptor rather than a FILE or their own
higher-level buffering structure, the design forces them to either
require that the file descriptor be seekable (so they can seek back
after reading too much) or read one byte at a time.

I'm not sure why someone would use file descriptors rather than stdio
or something similar for processing text.. Looks lke just a bad
design. There's no immediate fix, however, as the issue is a result of
the design.

Rich