From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mp12.migadu.com ([2001:41d0:2:bcc0::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by ms0.migadu.com with LMTPS id wFK8HKHdP2IvSgEAgWs5BA (envelope-from ) for ; Sun, 27 Mar 2022 05:44:33 +0200 Received: from aspmx1.migadu.com ([2001:41d0:2:bcc0::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by mp12.migadu.com with LMTPS id SAVaGaHdP2K5kAAAauVa8A (envelope-from ) for ; Sun, 27 Mar 2022 05:44:33 +0200 Received: from lists.gnu.org (lists.gnu.org [209.51.188.17]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by aspmx1.migadu.com (Postfix) with ESMTPS id C5412C49F for ; Sun, 27 Mar 2022 05:44:32 +0200 (CEST) Received: from localhost ([::1]:32832 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1nYJpQ-0004w7-0E for larch@yhetil.org; Sat, 26 Mar 2022 23:44:32 -0400 Received: from eggs.gnu.org ([209.51.188.92]:37566) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1nYJpD-0004vh-Bn for guix-devel@gnu.org; Sat, 26 Mar 2022 23:44:19 -0400 Received: from [2607:f8b0:4864:20::736] (port=38430 helo=mail-qk1-x736.google.com) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1nYJpB-00066u-5p; Sat, 26 Mar 2022 23:44:18 -0400 Received: by mail-qk1-x736.google.com with SMTP id d65so5485547qke.5; Sat, 26 Mar 2022 20:44:16 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=from:to:cc:subject:references:date:in-reply-to:message-id :user-agent:mime-version:content-transfer-encoding; bh=ADednl0HywpBCyd6kwwSSQ3Rmq9cIlBJHmKqtBnc4Bg=; b=MYdNQ3oMyhy9PdjnPr6ESwG+gGCuL/Lxko4B7yXfJrzNcQDUPoYeAVKw6rSNQeqYn+ MYk2zhmPkt5PFeRFGGJ2nRsv8Kz+fl7+MgDknHTQAP9f2ejMut2fVD+J4zvKeuJ/56Ja eAsP23MufOrd17atrSJV/dODB54uKgErVZDbHIq+2wRrIIreb43vI5YIpGRAiuqlBkHm NieamNvBqacQD1hUkK7FH0ScwPBWGACS7UYrQGebWIhjQ9cTOF58y+PKwo+1dQzluU/Z KQ2LxsXrBlZ+8MSNluk6g7slBhT5XPQhzjeMrdo6XPHvwWv7h7+FBLbbzBrNQiyvMaEI YXeg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:from:to:cc:subject:references:date:in-reply-to :message-id:user-agent:mime-version:content-transfer-encoding; bh=ADednl0HywpBCyd6kwwSSQ3Rmq9cIlBJHmKqtBnc4Bg=; b=mGDyDMsIdP3yWZjvj9OLCtWn3IlnIaZjtZMwx3J+jEYUJ32cuSW3ab9egYZjQ33bsD MUOmqAtZGc6nmS/mPquO2OJwkVyGDCpoGRxuzLfp4lR5iuoduXUYHRJS7XPAAGY6H/ol vRKBZjTdiTXrus5NnNvns7Ai9VxjfrGHpuSlT7VMDJfcsQE78ghzoMsy13l+Y0ZTS5hJ 9J/afLxVpRISInIweMn9wzUHaBcpPQMq53E+ikR9Hh/ua/5jw5Tgnk381Nzgnr+e/Vn2 yj98O9/GpugsI2xK+cKLHnNgaIZTbK/UZvxmDSwaX9EQzGU4VmSdXy1itNBlNMtmnpPo 1ytw== X-Gm-Message-State: AOAM530Qyx4mAoh3eQdBZ6ECLkgzG0Na3Btad/sHYlfy7NDrywrTonP4 gNh+6G4+Qw47GakK+qjUQ/ha68QR+ik= X-Google-Smtp-Source: ABdhPJzWlK137UcU6IWfLBpwidpgii52dZ0aNsOpAbp7pH6q+D5M/yk2591t6hzq7nWjPSAzyJWjjw== X-Received: by 2002:a37:54f:0:b0:67d:4926:5c49 with SMTP id 76-20020a37054f000000b0067d49265c49mr11867447qkf.507.1648352655147; Sat, 26 Mar 2022 20:44:15 -0700 (PDT) Received: from hurd (dsl-156-168.b2b2c.ca. [66.158.156.168]) by smtp.gmail.com with ESMTPSA id f18-20020a05622a105200b002e1eb06ece3sm8938810qte.31.2022.03.26.20.44.13 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Sat, 26 Mar 2022 20:44:14 -0700 (PDT) From: Maxim Cournoyer To: Ludovic =?utf-8?Q?Court=C3=A8s?= Subject: Re: Profiling of man-db database generation with zlib vs zstd References: <875yo53iuq.fsf@gmail.com> <87ee2r9gms.fsf@gnu.org> <87zgldwg87.fsf@gmail.com> Date: Sat, 26 Mar 2022 23:44:12 -0400 In-Reply-To: <87zgldwg87.fsf@gmail.com> (Maxim Cournoyer's message of "Fri, 25 Mar 2022 23:22:00 -0400") Message-ID: <87czi8vz3n.fsf@gmail.com> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.2 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Host-Lookup-Failed: Reverse DNS lookup failed for 2607:f8b0:4864:20::736 (failed) Received-SPF: pass client-ip=2607:f8b0:4864:20::736; envelope-from=maxim.cournoyer@gmail.com; helo=mail-qk1-x736.google.com X-Spam_score_int: -6 X-Spam_score: -0.7 X-Spam_bar: / X-Spam_report: (-0.7 / 5.0 requ) BAYES_00=-1.9, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, FREEMAIL_FROM=0.001, PDS_HP_HELO_NORDNS=0.659, RCVD_IN_DNSWL_NONE=-0.0001, RDNS_NONE=0.793, SPF_HELO_NONE=0.001, SPF_PASS=-0.001, T_SCC_BODY_TEXT_LINE=-0.01 autolearn=no autolearn_force=no X-Spam_action: no action X-BeenThere: guix-devel@gnu.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: "Development of GNU Guix and the GNU System distribution." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: guix-devel Errors-To: guix-devel-bounces+larch=yhetil.org@gnu.org Sender: "Guix-devel" X-Migadu-Flow: FLOW_IN X-Migadu-To: larch@yhetil.org X-Migadu-Country: US ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=yhetil.org; s=key1; t=1648352672; h=from:from:sender:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:cc:mime-version:mime-version: content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references:list-id:list-help: list-unsubscribe:list-subscribe:list-post:dkim-signature; bh=ADednl0HywpBCyd6kwwSSQ3Rmq9cIlBJHmKqtBnc4Bg=; b=UAU/CJFP3s9dJO3XDR6R/AJ+Au7ObsCjmO9zh11gPCrmzCvR8jJPhilvC3eaHLxd77yKRb mDDIO2mhIqZnS0RgI0Xg6S7y9ZuDKE8rPP4/qRABIaGMU9QXLzRAy2aKp6xwgOSWiThc6R ADQ/UBk61OpujVTc2cuQXpMIlvAecalZ/ve25GyVS57au8/MAQOSAsEbTkRIWAiODxygYQ JsRVoVD/jU1RNhbheEq0lYKsUBkkJPA51molHZYrJFfa1LLZLHfYg7vH3r8HS906zGZrnc SGtl8xsmuGz86+GaK4t/Ko3ExIIohHG8D0P/gU5g/xkqpsokVKE0gHMCUjhrtA== ARC-Seal: i=1; s=key1; d=yhetil.org; t=1648352672; a=rsa-sha256; cv=none; b=q2W8BxeiHUuNe/ypeoy9e/LxxaS7Iymu9D6sg5EDP2FO4iyI89vOG7qn05/tdj4sUnTD2d AHELzUk+kD4NSrEq/VS14x8YqjVrC7tRQntK7PkHOO3WXy2+Cu2IwUe5scFZkDgED6Gxcc m6Xk8ECYBcPkH8RfNXGzeFfXLlDg6/mqvHuLMM7rAHOCTmYFpNn0/1t7J6z+Q8Zcud0dRH uKTaUcn0xuTPgXiXUK++xq5naNIJ9HSrzePdO4lrq6HmBx0vQJDRnD14e8BWQZWsGAgvBa kCkuoHZ+wzQp3oW9h4G+g8U2kbJYdhMEPD9ugQsY5HYHVWoNKak6zu+xl5n+uQ== ARC-Authentication-Results: i=1; aspmx1.migadu.com; dkim=pass header.d=gmail.com header.s=20210112 header.b=MYdNQ3oM; dmarc=pass (policy=none) header.from=gmail.com; spf=pass (aspmx1.migadu.com: domain of "guix-devel-bounces+larch=yhetil.org@gnu.org" designates 209.51.188.17 as permitted sender) smtp.mailfrom="guix-devel-bounces+larch=yhetil.org@gnu.org" X-Migadu-Spam-Score: -6.37 Authentication-Results: aspmx1.migadu.com; dkim=pass header.d=gmail.com header.s=20210112 header.b=MYdNQ3oM; dmarc=pass (policy=none) header.from=gmail.com; spf=pass (aspmx1.migadu.com: domain of "guix-devel-bounces+larch=yhetil.org@gnu.org" designates 209.51.188.17 as permitted sender) smtp.mailfrom="guix-devel-bounces+larch=yhetil.org@gnu.org" X-Migadu-Queue-Id: C5412C49F X-Spam-Score: -6.37 X-Migadu-Scanner: scn0.migadu.com X-TUID: UwNfyuoBz2h/ Hello, Maxim Cournoyer writes: > Hi Ludovic! > > Ludovic Court=C3=A8s writes: > >> Hi, >> >> Maxim Cournoyer skribis: >> >>> scheme@(guix man-db)> ,profile (define a (mandb-entries "/gnu/store/jgc= 63dxvpd8zq0p8al71x07a02qj8i1b-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 >> =E2=80=98set-procedure-property!=E2=80=99 here? (Running =E2=80=98make= =E2=80=99 doesn=E2=80=99t compile it.) OK, I've now compiled guix/man-db.scm with -O3, generated a profile with ~5300 manuals (guix shell --no-grafts --pure man-db perl@5.14 man-pages libx11:doc gnutls-dane:doc my-tcl) on core-updates with my local changes to compress man pages with zstd and profiled: --8<---------------cut here---------------start------------->8--- scheme@(guix man-db)> ,profile (define a (mandb-entries "/gnu/store/jp1kjkz= 5m116r960gvjk1sj4b0fkb0ip-profile/share/man")) % cumulative self time seconds seconds procedure 69.37 16.19 16.15 %read-line 14.14 3.31 3.29 string-tokenize 5.76 1.34 1.34 gdbm.scm:122:11 2.44 22.75 0.57 guix/man-db.scm:170:4 1.92 1.71 0.45 make-bytevector 1.57 0.37 0.37 anon #x209d110 0.52 0.14 0.12 open-file 0.35 16.96 0.08 ice-9/rdelim.scm:193:0:read-line 0.35 0.08 0.08 stringpointer 0.26 0.06 0.06 assv-ref 0.26 0.06 0.06 readdir 0.26 0.06 0.06 equal? 0.26 0.06 0.06 get-bytevector-n! 0.17 0.67 0.04 zstd.scm:234:2:read! 0.17 0.04 0.04 string-append 0.17 0.04 0.04 close-port 0.17 0.04 0.04 bytevector-u64-native-set! 0.17 0.04 0.04 stat 0.17 0.04 0.04 guix/man-db.scm:139:19 0.09 1.83 0.02 zstd.scm:216:0:make-zstd-input-port 0.09 0.33 0.02 ice-9/ftw.scm:445:2:loop 0.09 0.12 0.02 system/foreign.scm:150:0:write-c-struct 0.09 0.04 0.02 system/foreign.scm:167:0:read-c-struct 0.09 0.02 0.02 pointer->bytevector 0.09 0.02 0.02 regexp-exec 0.09 0.02 0.02 string 0.09 0.02 0.02 sizeof 0.09 0.02 0.02 basename 0.09 0.02 0.02 string-contains 0.09 0.02 0.02 lstat 0.09 0.02 0.02 force 0.09 0.02 0.02 anon #x209d0d8 0.00 34249.92 0.00 ice-9/boot-9.scm:220:5:map1 0.00 23.28 0.00 :3:9 0.00 17.17 0.00 ice-9/ports.scm:429:0:call-with-port 0.00 7.46 0.00 zstd.scm:273:0:call-with-zstd-input-port 0.00 1.34 0.00 anon #x208c5f0 0.00 1.34 0.00 %after-gc-thunk 0.00 0.73 0.00 guix/man-db.scm:129:0:read-synopsis 0.00 0.67 0.00 %read-line 0.00 0.28 0.00 guix/man-db.scm:205:0:mandb-entries 0.00 0.16 0.00 srfi/srfi-1.scm:452:2:fold 0.00 0.16 0.00 anon #x208c57c 0.00 0.16 0.00 guix/build/utils.scm:487:0:find-files 0.00 0.14 0.00 guix/man-db.scm:155:0:man-page->entry 0.00 0.12 0.00 system/foreign.scm:182:0:make-c-struct 0.00 0.08 0.00 sort 0.00 0.04 0.00 filter 0.00 0.04 0.00 close-port 0.00 0.04 0.00 ice-9/boot-9.scm:1971:6 0.00 0.04 0.00 zstd.scm:208:4 0.00 0.04 0.00 guix/build/utils.scm:503:28 0.00 0.04 0.00 string-map 0.00 0.02 0.00 ice-9/boot-9.scm:1689:4:with-exception-handler 0.00 0.02 0.00 system/foreign.scm:187:0:parse-c-struct 0.00 0.02 0.00 guix/build/utils.scm:484:4 --- Sample count: 1146 Total time: 23.282459186 seconds (7.318256931 seconds in GC) --8<---------------cut here---------------end--------------->8--- It still shows that parsing the files is much more expensive than decompressing them. This is also true of zlib-compressed manuals; here's the same experiment on master: --8<---------------cut here---------------start------------->8--- $ guix shell --no-grafts --pure man-db perl@5.14 man-pages libx11:doc gnutl= s-dane:doc tcl [env]$ echo $GUIX_ENVIRONMENT && exit /gnu/store/qqd7d22wf9d220prkm682yypybpr7df4-profile $ guix shell -D guix guile-gdbm-ffi guile-zstd [env]$ guild compile -O3 guix/man-db.scm `/home/maxim/.cache/guile/ccache/3.0-LE-8-4.6/home/maxim/src/guix-master/gu= ix/man-db.scm.go' [env]$ ./pre-inst-env guix repl scheme@(guix-user)> ,m (guix man-db) scheme@(guix man-db)> ,profile (define a (mandb-entries "/gnu/store/qqd7d22= wf9d220prkm682yypybpr7df4-profile/share/man")) % cumulative self time seconds seconds procedure 49.15 2.62 2.56 string-tokenize 15.93 0.87 0.83 %read-line 10.85 0.57 0.57 anon #xd67e30 4.75 5.91 0.25 guix/man-db.scm:161:4 3.05 0.16 0.16 open-file 2.03 0.11 0.11 gdbm.scm:122:11 1.36 0.09 0.07 stat 1.36 0.07 0.07 stringpointer 0.68 0.04 0.04 guix/man-db.scm:134:19 0.68 0.04 0.04 bytevector->pointer 0.68 0.04 0.04 make-custom-binary-input-port 0.68 0.04 0.04 equal? 0.34 0.18 0.02 guix/man-db.scm:150:0:man-page->entry 0.34 0.02 0.02 basename 0.34 0.02 0.02 anon #xd67f10 0.34 0.02 0.02 ice-9/popen.scm:183:0:reap-pipes 0.34 0.02 0.02 zlib.scm:190:33 0.34 0.02 0.02 zlib.scm:66:0 0.00 10838.31 0.00 ice-9/boot-9.scm:220:5:map1 0.00 6.21 0.00 zlib.scm:217:0:call-with-gzip-input-port 0.00 5.22 0.00 :2:9 0.00 0.60 0.00 %read-line 0.00 0.60 0.00 zlib.scm:99:4 0.00 0.25 0.00 ice-9/ftw.scm:445:2:loop 0.00 0.25 0.00 guix/man-db.scm:196:0:mandb-entries 0.00 0.12 0.00 srfi/srfi-1.scm:452:2:fold 0.00 0.12 0.00 guix/build/utils.scm:476:0:find-files 0.00 0.12 0.00 zlib.scm:87:4 0.00 0.12 0.00 %after-gc-thunk 0.00 0.12 0.00 anon #xd5745c 0.00 0.12 0.00 anon #xd574d0 0.00 0.09 0.00 ice-9/boot-9.scm:1971:6 0.00 0.07 0.00 sort 0.00 0.07 0.00 guix/build/utils.scm:492:28 0.00 0.05 0.00 filter 0.00 0.05 0.00 ice-9/boot-9.scm:1689:4:with-exception-handler 0.00 0.04 0.00 string-map 0.00 0.04 0.00 guix/man-db.scm:200:26 0.00 0.04 0.00 close-port 0.00 0.02 0.00 guix/build/utils.scm:473:4 0.00 0.02 0.00 zlib.scm:138:4 --- Sample count: 295 Total time: 5.217801086 seconds (1.528583927 seconds in GC) --8<---------------cut here---------------end--------------->8--- Hum, OK, so if I understand guile-zstd causes an almost 5x slowdown... that doesn't make much sense unless the guile-zstd library is much slower itself (zstd-decompression should be about 3.5x faster than that of zlib). Supposing guile-zstd was a 1:1 equivalent to guile-zlib, then we should be able to see the above ~5 s time shrink down to around 1.5 s (best case), which would be nice. I'm impressed the man-db hook is that fast already though; I seem to recall it would take like 30 s (or more?) for such a large amount of man pages on this machine. Thanks, Maxim