[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: Profiling of man-db database generation with zlib vs zstd
|
From: |
Maxim Cournoyer |
|
Subject: |
Re: Profiling of man-db database generation with zlib vs zstd |
|
Date: |
Fri, 25 Mar 2022 23:22:00 -0400 |
|
User-agent: |
Gnus/5.13 (Gnus v5.13) Emacs/27.2 (gnu/linux) |
Hi Ludovic!
Ludovic Courtès <ludo@gnu.org> writes:
> Hi,
>
> Maxim Cournoyer <maxim.cournoyer@gmail.com> skribis:
>
>> 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
>
> Could it be that man-db.scm is being interpreted, hence eval.scm and
> ‘set-procedure-property!’ here? (Running ‘make’ doesn’t compile it.)
>
> With a compiled man-db.scm, I get:
>
> scheme@(guile-user)> ,profile (define a (mandb-entries
> "/gnu/store/jgc63dxvpd8zq0p8al71x07a02qj8i1b-man-pages-5.13/share/man"))
> % cumulative self
> time seconds seconds procedure
> 62.26 0.65 0.65 string-tokenize
> 11.32 0.12 0.12 anon #xc76118
> 3.77 0.16 0.04 ice-9/suspendable-ports.scm:651:0:read-delimited
> 3.77 0.04 0.04 open-file
> 1.89 1.35 0.02 /home/ludo/src/guix/guix/man-db.scm:161:4
> 1.89 0.04 0.02 stat
> 1.89 0.02 0.02 ice-9/popen.scm:183:0:reap-pipes
> 1.89 0.02 0.02 string->pointer
> 1.89 0.02 0.02 close-port
> 1.89 0.02 0.02 anon #xc760e0
> 1.89 0.02 0.02 fileno
> 1.89 0.02 0.02 string<?
> 1.89 0.02 0.02 ice-9/suspendable-ports.scm:203:4
> 1.89 0.02 0.02 lstat
> 0.00 1220.43 0.00 ice-9/boot-9.scm:220:5:map1
> 0.00 1.45 0.00 zlib.scm:217:0:call-with-gzip-input-port
> 0.00 1.05 0.00 <current input>:2756:9
> 0.00 0.12 0.00 ice-9/suspendable-ports.scm:70:0:read-bytes
> 0.00 0.12 0.00 port-read
> 0.00 0.12 0.00 zlib.scm:99:4
> 0.00 0.12 0.00 ice-9/suspendable-ports.scm:158:0:fill-input
> 0.00 0.08 0.00 zlib.scm:158:0:make-gzip-input-port
> 0.00 0.06 0.00
> /home/ludo/src/guix/guix/man-db.scm:196:0:mandb-entries
> 0.00 0.04 0.00 zlib.scm:87:4
> 0.00 0.04 0.00
> /home/ludo/src/guix/guix/man-db.scm:150:0:man-page->entry
> 0.00 0.04 0.00
> /home/ludo/src/guix/guix/man-db.scm:191:0:man-files
> 0.00 0.04 0.00 ice-9/ftw.scm:445:2:loop
> 0.00 0.04 0.00 ice-9/boot-9.scm:1971:6
> 0.00 0.02 0.00 %after-gc-thunk
> 0.00 0.02 0.00 anon #xbbc5b0
> 0.00 0.02 0.00 ice-9/boot-9.scm:1689:4:with-exception-handler
> 0.00 0.02 0.00 guix/build/utils.scm:476:0:find-files
> 0.00 0.02 0.00 sort
> 0.00 0.02 0.00 filter
> 0.00 0.02 0.00 /home/ludo/src/guix/guix/man-db.scm:200:26
> 0.00 0.02 0.00 srfi/srfi-1.scm:452:2:fold
> 0.00 0.02 0.00 anon #xbbc53c
> ---
> Sample count: 53
> Total time: 1.049704017 seconds (0.358461379 seconds in GC)
>
> More samples would give a more exploitable profile though.
Thanks! I tried generating a profile containing these high manpages
count: man-pages (~2400), perl (~800), libx11 (~800), gnutls (~1200),
tcl (~850), calibre (~700)
Which should give a collection of close to 7000 manpages, or roughly 3
times larger than 'man-pages' alone.
Unfortunately, it seems something else wants my attention:
--8<---------------cut here---------------start------------->8---
$ ./pre-inst-env guix shell --no-grafts --pure man-db perl@5.14 man-pages
libx11:doc gnutls-dane:doc my-tcl calibre
[...]
substitute: updating substitutes from 'http://127.0.0.1:8181'...
36.4%Backtrace:
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In unknown file:
substitute: 16 (apply-smob/0 #<thunk 7f343a1962e0>)
substitute: In ice-9/boot-9.scm:
substitute: 724:2 15 (call-with-prompt _ _ #<procedure
default-prompt-handle…>)
substitute: In ice-9/eval.scm:
substitute: 619:8 14 (_ #(#(#<directory (guile-user) 7f343a19bc80>)))
substitute: In guix/ui.scm:
substitute: 2247:7 13 (run-guix . _)
substitute: 2210:10 12 (run-guix-command _ . _)
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
substitute: 1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In guix/scripts/substitute.scm:
substitute: 757:18 9 (_)
substitute: 348:26 8 (process-query #<output: file 4> _ #:cache-urls _
#:acl _)
substitute: In guix/substitutes.scm:
substitute: 365:27 7 (lookup-narinfos/diverse _ _ #<procedure 7f3437718ee0
…> …)
substitute: 322:31 6 (lookup-narinfos _ _ #:open-connection _ # _)
substitute: 245:26 5 (fetch-narinfos _ _ #:open-connection _ # _)
substitute: In ice-9/boot-9.scm:
substitute: 1685:16 4 (raise-exception _ #:continuable? _)
substitute: 1685:16 3 (raise-exception _ #:continuable? _)
substitute: 1780:13 2 (_ #<&compound-exception components:
(#<&assertion-fail…>)
substitute: 1685:16 1 (raise-exception _ #:continuable? _)
substitute: 1685:16 0 (raise-exception _ #:continuable? _)
substitute:
substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
substitute: Wrong type (expecting exact integer): #f
guix shell: error:
`/gnu/store/pw3g3c2vpy6xyibp077875gb8xascgwa-guix-1.3.0-24.2fb4304/bin/guix
substitute' died unexpectedly
$ ./pre-inst-env guix shell --no-grafts --pure man-db perl@5.14 man-pages
libx11:doc gnutls-dane:doc my-tcl calibre
[...]
substitute: updating substitutes from 'http://127.0.0.1:8181'...
25.2%Backtrace:
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In unknown file:
substitute: 16 (apply-smob/0 #<thunk 7f5a78cef2e0>)
substitute: In ice-9/boot-9.scm:
substitute: 724:2 15 (call-with-prompt _ _ #<procedure
default-prompt-handle…>)
substitute: In ice-9/eval.scm:
substitute: 619:8 14 (_ #(#(#<directory (guile-user) 7f5a78cf4c80>)))
substitute: In guix/ui.scm:
substitute: 2247:7 13 (run-guix . _)
substitute: 2210:10 12 (run-guix-command _ . _)
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
substitute: 1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In guix/scripts/substitute.scm:
substitute: 757:18 9 (_)
substitute: 348:26 8 (process-query #<output: file 4> _ #:cache-urls _
#:acl _)
substitute: In guix/substitutes.scm:
substitute: 365:27 7 (lookup-narinfos/diverse _ _ #<procedure 7f5a76252e00
…> …)
substitute: 322:31 6 (lookup-narinfos _ _ #:open-connection _ # _)
substitute: 245:26 5 (fetch-narinfos _ _ #:open-connection _ # _)
substitute: In ice-9/boot-9.scm:
substitute: 1685:16 4 (raise-exception _ #:continuable? _)
substitute: 1685:16 3 (raise-exception _ #:continuable? _)
substitute: 1780:13 2 (_ #<&compound-exception components:
(#<&assertion-fail…>)
substitute: 1685:16 1 (raise-exception _ #:continuable? _)
substitute: 1685:16 0 (raise-exception _ #:continuable? _)
substitute:
substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
substitute: Wrong type (expecting exact integer): #f
guix shell: error:
`/gnu/store/pw3g3c2vpy6xyibp077875gb8xascgwa-guix-1.3.0-24.2fb4304/bin/guix
substitute' died unexpectedly
$ ./pre-inst-env guix shell --no-grafts --pure man-db perl@5.14 man-pages
libx11:doc gnutls-dane:doc my-tcl calibre
[...]
substitute: updating substitutes from 'http://127.0.0.1:8181'...
32.0%Backtrace:
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In unknown file:
substitute: 16 (apply-smob/0 #<thunk 7ff772ca92e0>)
substitute: In ice-9/boot-9.scm:
substitute: 724:2 15 (call-with-prompt _ _ #<procedure
default-prompt-handle…>)
substitute: In ice-9/eval.scm:
substitute: 619:8 14 (_ #(#(#<directory (guile-user) 7ff772caec80>)))
substitute: In guix/ui.scm:
substitute: 2247:7 13 (run-guix . _)
substitute: 2210:10 12 (run-guix-command _ . _)
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
substitute: 1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In guix/scripts/substitute.scm:
substitute: 757:18 9 (_)
substitute: 348:26 8 (process-query #<output: file 4> _ #:cache-urls _
#:acl _)
substitute: In guix/substitutes.scm:
substitute: 365:27 7 (lookup-narinfos/diverse _ _ #<procedure 7ff770204b40
…> …)
substitute: 322:31 6 (lookup-narinfos _ _ #:open-connection _ # _)
substitute: 245:26 5 (fetch-narinfos _ _ #:open-connection _ # _)
substitute: In ice-9/boot-9.scm:
substitute: 1685:16 4 (raise-exception _ #:continuable? _)
substitute: 1685:16 3 (raise-exception _ #:continuable? _)
substitute: 1780:13 2 (_ #<&compound-exception components:
(#<&assertion-fail…>)
substitute: 1685:16 1 (raise-exception _ #:continuable? _)
substitute: 1685:16 0 (raise-exception _ #:continuable? _)
substitute:
substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
substitute: Wrong type (expecting exact integer): #f
guix shell: error:
`/gnu/store/pw3g3c2vpy6xyibp077875gb8xascgwa-guix-1.3.0-24.2fb4304/bin/guix
substitute' died unexpectedly
$ ./pre-inst-env guix shell --no-grafts --pure man-db perl@5.14 man-pages
libx11:doc gnutls-dane:doc my-tcl calibre
[...]
substitute: updating substitutes from 'http://127.0.0.1:8181'... 100.0%
substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
guix shell: error: got unexpected path
`/gnu/store/67awg434br6215jxvf3h2r6imawsbky0-cairomm-1.14.2.tar.xz' from
substituter
./pre-inst-env guix shell --no-grafts --pure man-db perl@5.14 man-pages
libx11:doc gnutls-dane:doc my-tcl calibre
[...]
substitute: updating substitutes from 'http://127.0.0.1:8181'...
18.5%Backtrace:
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In unknown file:
substitute: 16 (apply-smob/0 #<thunk 7fd517c2a2e0>)
substitute: In ice-9/boot-9.scm:
substitute: 724:2 15 (call-with-prompt _ _ #<procedure
default-prompt-handle…>)
substitute: In ice-9/eval.scm:
substitute: 619:8 14 (_ #(#(#<directory (guile-user) 7fd517c2fc80>)))
substitute: In guix/ui.scm:
substitute: 2247:7 13 (run-guix . _)
substitute: 2210:10 12 (run-guix-command _ . _)
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
substitute: 1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In guix/scripts/substitute.scm:
substitute: 757:18 9 (_)
substitute: 348:26 8 (process-query #<output: file 4> _ #:cache-urls _
#:acl _)
substitute: In guix/substitutes.scm:
substitute: 365:27 7 (lookup-narinfos/diverse _ _ #<procedure 7fd5151770e0
…> …)
substitute: 322:31 6 (lookup-narinfos _ _ #:open-connection _ # _)
substitute: 245:26 5 (fetch-narinfos _ _ #:open-connection _ # _)
substitute: In ice-9/boot-9.scm:
substitute: 1685:16 4 (raise-exception _ #:continuable? _)
substitute: 1685:16 3 (raise-exception _ #:continuable? _)
substitute: 1780:13 2 (_ #<&compound-exception components: (#<&error>
#<&orig…>)
substitute: 1685:16 1 (raise-exception _ #:continuable? _)
substitute: 1685:16 0 (raise-exception _ #:continuable? _)
substitute:
substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
substitute: unmatched line "\r"
guix shell: error:
`/gnu/store/pw3g3c2vpy6xyibp077875gb8xascgwa-guix-1.3.0-24.2fb4304/bin/guix
substitute' died unexpectedly
$ ./pre-inst-env guix shell --no-grafts --pure man-db perl@5.14 man-pages
libx11:doc gnutls-dane:doc my-tcl calibre
[...]
substitute: updating substitutes from 'http://127.0.0.1:8181'...
22.3%Backtrace:
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 17 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In unknown file:
substitute: 16 (apply-smob/0 #<thunk 7fbb72b382e0>)
substitute: In ice-9/boot-9.scm:
substitute: 724:2 15 (call-with-prompt _ _ #<procedure
default-prompt-handle…>)
substitute: In ice-9/eval.scm:
substitute: 619:8 14 (_ #(#(#<directory (guile-user) 7fbb72b3dc80>)))
substitute: In guix/ui.scm:
substitute: 2247:7 13 (run-guix . _)
substitute: 2210:10 12 (run-guix-command _ . _)
substitute: In ice-9/boot-9.scm:
substitute: 1752:10 11 (with-exception-handler _ _ #:unwind? _ # _)
substitute: 1752:10 10 (with-exception-handler _ _ #:unwind? _ # _)
substitute: In guix/scripts/substitute.scm:
substitute: 757:18 9 (_)
substitute: 348:26 8 (process-query #<output: file 4> _ #:cache-urls _
#:acl _)
substitute: In guix/substitutes.scm:
substitute: 365:27 7 (lookup-narinfos/diverse _ _ #<procedure 7fbb7007c160
…> …)
substitute: 322:31 6 (lookup-narinfos _ _ #:open-connection _ # _)
substitute: 245:26 5 (fetch-narinfos _ _ #:open-connection _ # _)
substitute: In ice-9/boot-9.scm:
substitute: 1685:16 4 (raise-exception _ #:continuable? _)
substitute: 1685:16 3 (raise-exception _ #:continuable? _)
substitute: 1780:13 2 (_ #<&compound-exception components:
(#<&assertion-fail…>)
substitute: 1685:16 1 (raise-exception _ #:continuable? _)
substitute: 1685:16 0 (raise-exception _ #:continuable? _)
substitute:
substitute: ice-9/boot-9.scm:1685:16: In procedure raise-exception:
substitute: Wrong type (expecting exact integer): #f
guix shell: error:
`/gnu/store/pw3g3c2vpy6xyibp077875gb8xascgwa-guix-1.3.0-24.2fb4304/bin/guix
substitute' died unexpectedly
--8<---------------cut here---------------end--------------->8---
I forgot where I was at the last time I tried to debug this :-).
Thanks, I'll try to follow-up with the actual results if I can sort the
above.
Maxim