[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Profiling of man-db database generation with zlib vs zstd
|
From: |
Maxim Cournoyer |
|
Subject: |
Profiling of man-db database generation with zlib vs zstd |
|
Date: |
Tue, 22 Mar 2022 15:09:01 -0400 |
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
- Profiling of man-db database generation with zlib vs zstd,
Maxim Cournoyer <=