From: Maxim Cournoyer <maxim.cournoyer@gmail.com>
To: "Ludovic Courtès" <ludo@gnu.org>
Cc: guix-devel <guix-devel@gnu.org>
Subject: Re: Profiling of man-db database generation with zlib vs zstd
Date: Fri, 25 Mar 2022 23:22:00 -0400 [thread overview]
Message-ID: <87zgldwg87.fsf@gmail.com> (raw)
In-Reply-To: <87ee2r9gms.fsf@gnu.org> ("Ludovic Courtès"'s message of "Thu, 24 Mar 2022 22:37:15 +0100")
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
next prev parent reply other threads:[~2022-03-26 3:22 UTC|newest]
Thread overview: 10+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-03-22 19:09 Profiling of man-db database generation with zlib vs zstd Maxim Cournoyer
2022-03-24 21:37 ` Ludovic Courtès
2022-03-26 3:22 ` Maxim Cournoyer [this message]
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
List information: https://guix.gnu.org/
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=87zgldwg87.fsf@gmail.com \
--to=maxim.cournoyer@gmail.com \
--cc=guix-devel@gnu.org \
--cc=ludo@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 public inbox
https://git.savannah.gnu.org/cgit/guix.git
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).