From: Maxim Cournoyer <maxim.cournoyer@gmail.com>
To: guix-devel <guix-devel@gnu.org>
Subject: Profiling of man-db database generation with zlib vs zstd
Date: Tue, 22 Mar 2022 15:09:01 -0400 [thread overview]
Message-ID: <875yo53iuq.fsf@gmail.com> (raw)
Hello Guix,
I've spent some time looking whether the manual database generation
could be sped up by switching from compressing the manual pages with
zstd instead of zlib, which is reported to be about 3.5 times faster to
decompress.
I thought decompression would play a role because the hook is
CPU-intensive and thousands of files (depending on your profile) need to
be decompressed in order to be parsed.
But my experiment suggests otherwise: switching from zlib to zstd
currently wouldn't buy us any gain; and profiling the mandb-entries from
(guix man-db) shows something like this (current, zlib compression):
--8<---------------cut here---------------start------------->8---
scheme@(guix man-db)> ,profile (define a (mandb-entries "/gnu/store/jgc63dxvpd8zq0p8al71x07a02qj8i1b-man-pages-5.13/share/man"))
% cumulative self
time seconds seconds procedure
20.95 1.98 1.75 gdbm.scm:122:11
20.95 1.75 1.75 string-tokenize
19.37 3.61 1.62 set-procedure-property!
6.72 0.56 0.56 ice-9/eval.scm:604:6
4.35 0.36 0.36 %read-line
4.35 0.36 0.36 anon #xa8e0b0
2.77 0.23 0.23 apply-smob/1
1.58 11.51 0.13 ice-9/eval.scm:292:11
1.58 0.20 0.13 open-file
1.58 0.13 0.13 ice-9/eval.scm:333:13
1.19 0.20 0.10 ice-9/eval.scm:263:9
1.19 0.13 0.10 ice-9/eval.scm:297:11
0.79 0.66 0.07 ice-9/eval.scm:159:9
0.79 0.07 0.07 ice-9/eval.scm:187:12
0.79 0.07 0.07 ice-9/popen.scm:183:0:reap-pipes
0.79 0.07 0.07 stat
0.79 0.07 0.07 ice-9/eval.scm:273:7
0.79 0.07 0.07 make-custom-binary-input-port
0.79 0.07 0.07 anon #xa8e078
0.79 0.07 0.07 ice-9/eval.scm:123:11
0.40 0.76 0.03 ice-9/rdelim.scm:193:0:read-line
0.40 0.20 0.03 ice-9/ftw.scm:445:2:loop
0.40 0.17 0.03 zlib.scm:158:0:make-gzip-input-port
0.40 0.03 0.03 ice-9/eval.scm:182:7
0.40 0.03 0.03 ice-9/eval.scm:329:11
0.40 0.03 0.03 string-trim-both
0.40 0.03 0.03 ice-9/eval.scm:125:11
0.40 0.03 0.03 dup->fdes
0.40 0.03 0.03 ice-9/eval.scm:226:7
0.40 0.03 0.03 string<?
0.40 0.03 0.03 ice-9/eval.scm:330:13
0.40 0.03 0.03 equal?
0.40 0.03 0.03 ice-9/eval.scm:155:9
0.40 0.03 0.03 ice-9/eval.scm:124:11
0.40 0.03 0.03 regexp-exec
0.40 0.03 0.03 ice-9/eval.scm:417:6
0.40 0.03 0.03 zlib.scm:66:0
0.40 0.03 0.03 ice-9/ftw.scm:218:12:string=?@guile
0.00 10070.94 0.00 ice-9/boot-9.scm:220:5:map1
0.00 12.57 0.00 zlib.scm:217:0:call-with-gzip-input-port
0.00 8.37 0.00 <current input>:11:9
0.00 3.64 0.00 ice-9/eval.scm:586:29
0.00 2.05 0.00 %after-gc-thunk
0.00 2.05 0.00 anon #xa7d750
0.00 1.98 0.00 ice-9/eval.scm:212:12
0.00 1.46 0.00 string-map
0.00 0.36 0.00 %read-line
0.00 0.36 0.00 zlib.scm:99:4
0.00 0.20 0.00 ice-9/eval.scm:618:6
0.00 0.10 0.00 guix/build/utils.scm:476:0:find-files
0.00 0.10 0.00 ice-9/eval.scm:244:10
0.00 0.10 0.00 anon #xa7d6dc
0.00 0.10 0.00 ice-9/eval.scm:625:6
0.00 0.10 0.00 srfi/srfi-1.scm:452:2:fold
0.00 0.07 0.00 zlib.scm:87:4
0.00 0.07 0.00 ice-9/boot-9.scm:1971:6
0.00 0.03 0.00 sort
0.00 0.03 0.00 ice-9/eval.scm:263:9
0.00 0.03 0.00 guix/build/utils.scm:492:28
---
Sample count: 253
Total time: 8.368360886 seconds (5.356567327 seconds in GC)
--8<---------------cut here---------------end--------------->8---
When rebuilding the man-pages package with zstd compressed manuals and
using guile-zstd to read them, we instead get:
--8<---------------cut here---------------start------------->8---
scheme@(guix man-db)> ,profile (define a (mandb-entries "/gnu/store/dsm4wkzgzq6i00xc765vpgdzb0aq99fa-man-pages-5.13/share/man"))
% cumulative self
time seconds seconds procedure
28.93 2.38 2.34 gdbm.scm:122:11
18.60 3.82 1.51 set-procedure-property!
12.81 1.04 1.04 string-tokenize
7.02 0.57 0.57 ice-9/eval.scm:604:6
4.55 0.37 0.37 make-bytevector
4.13 0.33 0.33 %read-line
3.31 0.27 0.27 anon #x1bb01e0
1.65 0.17 0.13 ice-9/eval.scm:263:9
1.65 0.13 0.13 stat
1.24 0.90 0.10 ice-9/rdelim.scm:193:0:read-line
1.24 0.10 0.10 ice-9/eval.scm:342:13
1.24 0.10 0.10 ice-9/eval.scm:125:11
1.24 0.10 0.10 regexp-exec
0.83 0.10 0.07 ice-9/eval.scm:155:9
0.83 0.07 0.07 ice-9/eval.scm:333:13
0.83 0.07 0.07 pointer->bytevector
0.83 0.07 0.07 anon #x1bb01a8
0.83 0.07 0.07 ice-9/eval.scm:187:12
0.83 0.07 0.07 string<?
0.83 0.07 0.07 get-bytevector-n!
0.41 11.92 0.03 zstd.scm:273:0:call-with-zstd-input-port
0.41 10.72 0.03 ice-9/eval.scm:292:11
0.41 1.91 0.03 ice-9/eval.scm:212:12
0.41 0.03 0.03 ice-9/eval.scm:123:11
0.41 0.03 0.03 ice-9/eval.scm:273:7
0.41 0.03 0.03 string-suffix?
0.41 0.03 0.03 ice-9/eval.scm:155:9
0.41 0.03 0.03 readdir
0.41 0.03 0.03 system/foreign.scm:188:20
0.41 0.03 0.03 ice-9/eval.scm:182:7
0.41 0.03 0.03 apply-smob/1
0.41 0.03 0.03 string-contains
0.41 0.03 0.03 ice-9/rdelim.scm:93:23:string-append@guile
0.41 0.03 0.03 equal?
0.41 0.03 0.03 close-port
0.41 0.03 0.03 ice-9/eval.scm:126:12
0.00 9965.18 0.00 ice-9/boot-9.scm:220:5:map1
0.00 8.10 0.00 <current input>:5:9
0.00 3.82 0.00 ice-9/eval.scm:586:29
0.00 2.38 0.00 anon #x1b9f6c0
0.00 2.38 0.00 %after-gc-thunk
0.00 1.57 0.00 string-map
0.00 0.57 0.00 ice-9/eval.scm:159:9
0.00 0.47 0.00 %read-line
0.00 0.47 0.00 zstd.scm:234:2:read!
0.00 0.44 0.00 zstd.scm:216:0:make-zstd-input-port
0.00 0.27 0.00 ice-9/ftw.scm:445:2:loop
0.00 0.17 0.00 srfi/srfi-1.scm:452:2:fold
0.00 0.13 0.00 ice-9/boot-9.scm:1971:6
0.00 0.13 0.00 ice-9/eval.scm:196:12
0.00 0.13 0.00 ice-9/eval.scm:618:6
0.00 0.13 0.00 guix/build/utils.scm:487:0:find-files
0.00 0.13 0.00 anon #x1b9f64c
0.00 0.13 0.00 ice-9/eval.scm:297:11
0.00 0.10 0.00 ice-9/eval.scm:244:10
0.00 0.10 0.00 system/foreign.scm:187:0:parse-c-struct
0.00 0.10 0.00 guix/build/utils.scm:503:28
0.00 0.07 0.00 ice-9/eval.scm:278:9
0.00 0.07 0.00 zstd.scm:208:4
0.00 0.07 0.00 filter
0.00 0.07 0.00 ice-9/eval.scm:625:6
0.00 0.07 0.00 sort
0.00 0.07 0.00 ice-9/eval.scm:259:9
0.00 0.03 0.00 open-file
0.00 0.03 0.00 close-port
0.00 0.03 0.00 ice-9/eval.scm:191:12
0.00 0.03 0.00 bytevector->pointer
---
Sample count: 242
Total time: 8.104984533 seconds (5.253193735 seconds in GC)
--8<---------------cut here---------------end--------------->8---
So, it seems the parsing of the manual files itself in Guile (to
retrieve their name, synopsis, etc.) is what is using most of the time
(CPU-bound).
Perhaps this can be optimized?
Maxim
next reply other threads:[~2022-03-22 19:09 UTC|newest]
Thread overview: 10+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-03-22 19:09 Maxim Cournoyer [this message]
2022-03-24 21:37 ` Profiling of man-db database generation with zlib vs zstd Ludovic Courtès
2022-03-26 3:22 ` Maxim Cournoyer
2022-03-27 3:44 ` Maxim Cournoyer
2022-03-29 10:22 ` Ludovic Courtès
2022-03-28 3:49 ` Maxim Cournoyer
2022-03-29 10:30 ` Ludovic Courtès
2022-03-30 14:49 ` Maxim Cournoyer
2022-03-30 16:16 ` Jonathan McHugh
2022-03-31 17:13 ` Ludovic Courtès
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=875yo53iuq.fsf@gmail.com \
--to=maxim.cournoyer@gmail.com \
--cc=guix-devel@gnu.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
Code repositories for project(s) associated with this external index
https://git.savannah.gnu.org/cgit/guix.git
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.