Entries page performance

[lemon24]

The entries (main) page takes too much time to load.

Some of that is due to get_entries() being slow, but most of the time seems to be spent rendering the page.

On my laptop:

$ /usr/bin/time -f 'real %e' curl http://localhost:8000/ -s | grep 'class="entry"' -Fc
real 1.25
550
$ /usr/bin/time -f 'real %e' curl http://localhost:8000/?show=all -s | grep 'class="entry"' -Fc
real 5.96
2507
$ /usr/bin/time -f 'real %e' curl http://localhost:8000/feeds -s | grep 'class="feed"' -Fc
real 0.14
50
$ curl http://localhost:8000/?show=all >/dev/null
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 3476k  100 3476k    0     0   686k      0  0:00:05  0:00:05 --:--:--  900k

In [1]: import reader

In [2]: r = reader.Reader('db.sqlite')

In [3]: %time len(list(r.get_entries(which='unread')))
CPU times: user 72.7 ms, sys: 47.7 ms, total: 120 ms
Wall time: 119 ms
Out[3]: 550

In [4]: %time len(list(r.get_entries()))
CPU times: user 669 ms, sys: 216 ms, total: 884 ms
Wall time: 883 ms
Out[4]: 2507

In [5]: %time len(list(r.get_feeds()))
CPU times: user 2.31 ms, sys: 0 ns, total: 2.31 ms
Wall time: 1.79 ms
Out[5]: 50

On a t2.micro EC2 instance (update: these might be due to bad internet, as it improved later):

$ /usr/bin/time -f 'real %e' curl https://t2-micro-ec2-instance-2000km-away/ -s | grep 'class="entry"' -Fc
real 18.16
548
$ /usr/bin/time -f 'real %e' curl https://t2-micro-ec2-instance-2000km-away/?show=all -s | grep 'class="entry"' -Fc
real 77.42
2505
$ /usr/bin/time -f 'real %e' curl https://t2-micro-ec2-instance-2000km-away/feeds -s | grep 'class="feed"' -Fc
real 1.23
50
$ curl https://t2-micro-ec2-instance-2000km-away/?show=all >/dev/null
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 3533k  100 3533k    0     0  42323      0  0:01:25  0:01:25 --:--:-- 50602

In [1]: import reader

In [2]: r = reader.Reader('/data/www-data/reader.sqlite')

In [3]: %time len(list(r.get_entries(which='unread')))
CPU times: user 44 ms, sys: 16 ms, total: 60 ms
Wall time: 60.9 ms
Out[3]: 548

In [4]: %time len(list(r.get_entries()))
CPU times: user 280 ms, sys: 84 ms, total: 364 ms
Wall time: 364 ms
Out[4]: 2505

In [5]: %time len(list(r.get_feeds()))
CPU times: user 0 ns, sys: 0 ns, total: 0 ns
Wall time: 826 µs
Out[5]: 50

[lemon24]

These two different runs of bench.py (on a different laptop) show that:

• get_entries() time is less than 10% of the total time to get the main page
• most of the time is spent generating the template output (render when rendering, generate when generating)

This probably means that there are no quick gains to be had (aside from running on pypy, but that's not an app improvement).

Remaining options I can think of:

• don't get all the entries in a single request (i.e. use pagination; already have support for this here, just need to expose it in the API); this was the sensible thing to do anyway
• optimize the template to generate fewer pieces per entry; doesn't scale (there's only so much you can improve)

[lemon24]

The following confirm that the huge time I got initially with curl for the instance was most likely due to network slowness. Also, it turns out the run on the original laptop was done with FLASK_DEBUG=1, which added about 2s to the /?show=all curl.

original-laptop$ python bench.py time
entries runs get_entries /?show=all ratio
...
   4096    1        0.25       3.33  13.2

t2-micro-ec2-instance$ python bench.py time
entries runs get_entries /?show=all ratio
 ...
   4096    1        0.13       2.09  16.7

$ /usr/bin/time -f 'real %e' curl https://t2-micro-ec2-instance-2000km-away/ -s | grep 'class="entry"' -Fc
real 5.19
2518

[lemon24]

This gist shows that using generate()/stream() instead of render() does decrease the time it takes to get the first 100kb of the page (as expected).

[lemon24]

This looks good enough for now. Will only implement pagination if it gets much worse.

$ /usr/bin/time -f 'real %e' curl https://t2-micro-ec2-instance-2000km-away/ -s | grep 'class="entry"' -Fc
real 2.78
2518
$ /usr/bin/time -f 'real %e' curl https://t2-micro-ec2-instance-2000km-away/ -s | head -c 100000 | grep 'class="entry"' -Fc
78
Command exited with non-zero status 23
real 0.85