From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.io!.POSTED.ciao.gmane.io!not-for-mail From: =?UTF-8?Q?Aleix_Conchillo_Flaqu=C3=A9?= Newsgroups: gmane.lisp.guile.user,gmane.lisp.guile.devel Subject: Re: Guile's time execution issues Date: Sun, 26 Apr 2020 16:14:32 -0700 Message-ID: References: <87d07u182a.fsf@gnu.org> Mime-Version: 1.0 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable Injection-Info: ciao.gmane.io; posting-host="ciao.gmane.io:159.69.161.202"; logging-data="31821"; mail-complaints-to="usenet@ciao.gmane.io" Cc: guile-user , guile-devel To: =?UTF-8?Q?Ludovic_Court=C3=A8s?= Original-X-From: guile-user-bounces+guile-user=m.gmane-mx.org@gnu.org Mon Apr 27 01:15:08 2020 Return-path: Envelope-to: guile-user@m.gmane-mx.org Original-Received: from lists.gnu.org ([209.51.188.17]) by ciao.gmane.io with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1jSqUN-00088g-L9 for guile-user@m.gmane-mx.org; Mon, 27 Apr 2020 01:15:07 +0200 Original-Received: from localhost ([::1]:48526 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1jSqUM-0006cy-Al for guile-user@m.gmane-mx.org; Sun, 26 Apr 2020 19:15:06 -0400 Original-Received: from eggs.gnu.org ([2001:470:142:3::10]:44748) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1jSqU8-0006cd-O4 for guile-user@gnu.org; Sun, 26 Apr 2020 19:14:53 -0400 Original-Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.90_1) (envelope-from ) id 1jSqU7-0001Gy-P3 for guile-user@gnu.org; Sun, 26 Apr 2020 19:14:52 -0400 Original-Received: from mail-lf1-x12d.google.com ([2a00:1450:4864:20::12d]:38343) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1jSqU3-0001FW-5n; Sun, 26 Apr 2020 19:14:47 -0400 Original-Received: by mail-lf1-x12d.google.com with SMTP id l11so12284175lfc.5; Sun, 26 Apr 2020 16:14:45 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=cSoKbHuSb6sLkQzuidBe73BGsbCeTwNn4eYr26GT4Cc=; b=lXlHh43sWP2G6yiOVUNxZGArUMqfDmFBDq243hyHSQiDknoS/kfwrj1uwvLyBOlkkO 2Q8s9ZLjeJBtt9ZGWZ6bFnTgOXNTTtr+WjRleOVsQa+9Mnmq66ze8T0HOtvM/JmZye4g SvW+882r/Qh1qA7yFGl59/sHoyAlKBw8npeFEKOHh25mcFwSlMVwUOvvyxid/Rg1/do2 picde/5twm02Dma0YK1VL3qPGJw9yvc7GxoEjt5wd8bZVjjABRImbhkJ7apyWsYAKKwd HeimwiD0xoOf2c7g++IgEeEBZnQG8/EEz3wtjGXdKUecD/czVoMLpTg/Cc6peg8qsKIu Pg8w== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=cSoKbHuSb6sLkQzuidBe73BGsbCeTwNn4eYr26GT4Cc=; b=Whs82CeGlR3Dfuf5cCnzSzPFwp9P8pcqvRm0kfsreZa4sf/TnS31GA+UXWpeyJML4X NvxAN3rcpQDZ7CyKaYjdUilaEyd4CPZKNiUMRONMysyeJCNxc9S69UnHmR9sPYg4TbkU +bFXawqb2qBAufk5962SXtmCuGsRTIEAhbEIBaqrWD3Fk6hiqeq/lcTasdMd9zGsSB/e E1wRBlqoE7XzWuL9/IHz4PKkAFPkSTixjHhw/DEB18FY/oXUO6OFepFx5crXLs6llana 4z3jOURkWTHE5FX+bWPxaLVHZbBl3meBTl9pyEvRBEo+l/P3YUPgC0SwUninGWi849l9 ktyQ== X-Gm-Message-State: AGi0PuZTVN1p7OTW4s+MDtsdwB/kbroXS8JnqUVaiT0VwbXqrEVP367v Bg+kIkyDxxdBFv8DngjGaA7J01BP02SQlIt0UjjQBMiGbg8= X-Google-Smtp-Source: APiQypKPXyuMaEZMbdNW0Y9PQpCvy5WbUwRM9k9B8DkxryQAd5UincRuiK7amn6ziKbc1xk9xZXJQPsdO/e6AUI2Kp4= X-Received: by 2002:ac2:4143:: with SMTP id c3mr13713527lfi.131.1587942883580; Sun, 26 Apr 2020 16:14:43 -0700 (PDT) In-Reply-To: <87d07u182a.fsf@gnu.org> Received-SPF: pass client-ip=2a00:1450:4864:20::12d; envelope-from=aconchillo@gmail.com; helo=mail-lf1-x12d.google.com X-detected-operating-system: by eggs.gnu.org: Error: [-] PROGRAM ABORT : Malformed IPv6 address (bad octet value). Location : parse_addr6(), p0f-client.c:67 X-Received-From: 2a00:1450:4864:20::12d X-Content-Filtered-By: Mailman/MimeDel 2.1.23 X-BeenThere: guile-user@gnu.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: General Guile related discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: guile-user-bounces+guile-user=m.gmane-mx.org@gnu.org Original-Sender: "guile-user" Xref: news.gmane.io gmane.lisp.guile.user:16406 gmane.lisp.guile.devel:20496 Archived-At: On Sun, Apr 26, 2020 at 10:16 AM Ludovic Court=C3=A8s wrote: > Bon dia! > > Bon dia! And bon jour! :-D > Aleix Conchillo Flaqu=C3=A9 skribis: > > > I was trying to get some guile-json performance times loading large JSO= N > > file. However, I'm getting increasing numbers at each run, so I'm > wondering > > if I'm doing something wrong. Below you can see how the first run took > > 19.95s and then running the same command kept increasing. > > > > I'm running Guile 2.2.7 on macOS Catalina 10.15.3. > > > > scheme@(guile-user)> (use-modules (json)) > > scheme@(guile-user)> ,t (define a (call-with-input-file > > "/Users/aleix/Downloads/large-file.json" (lambda (port) (json->scm > port)))) > > ;; 19.956429s real time, 87.100982s run time. 75.270202s spent in GC. > > ;; 26.173179s real time, 143.645265s run time. 131.022631s spent in GC= . > > ;; 28.193926s real time, 154.758375s run time. 141.697236s spent in GC= . > > ;; 29.044218s real time, 160.745984s run time. 147.449073s spent in GC= . > > ;; 30.480873s real time, 170.855527s run time. 157.332793s spent in GC= . > > ;; 30.555700s real time, 172.938278s run time. 159.468737s spent in GC= . > > ;; 32.190478s real time, 172.807551s run time. 158.905645s spent in GC= . > > Could this have to do with ? > > Honestly, I have no idea... :-( Could you check if that happens with 3.0.2? (Or suggest a > =E2=80=98large-file.json=E2=80=99 to use. :-)) > > Sure! I suggested a JSON, it was hidden at the end of my first message ;-). This is the one: https://github.com/json-iterator/test-data/blob/master/large-file.json So, bad and good news for Guile 3.0.2. I'm trying it inside Docker using this image https://hub.docker.com/r/schemers/guile. On guile-json 3.5.0 (still using (string-append)) the first execution time goes from 19 seconds to 42 seconds. Then, the times keep increasing as in version 2.2.7 but numbers are much bigger: # ./env guile GNU Guile 3.0.2 Copyright (C) 1995-2020 Free Software Foundation, Inc. Guile comes with ABSOLUTELY NO WARRANTY; for details type `,show w'. This program is free software, and you are welcome to redistribute it under certain conditions; type `,show c' for details. Enter `,help' for help. scheme@(guile-user)> (use-modules (json)) scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 42.015887s real time, 42.059462s run time. 32.838460s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 56.228837s real time, 56.176989s run time. 46.112349s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 63.472869s real time, 63.383118s run time. 52.642226s spent in GC. The good news is that on master branch I don't use (string-append) anymore and it goes from 19 seconds (in 2.2.7) to ~6 seconds (both in 2.2.7 and 3.0.2). =E2=9D=AF ./env guile GNU Guile 2.2.7 Copyright (C) 1995-2019 Free Software Foundation, Inc. Guile comes with ABSOLUTELY NO WARRANTY; for details type `,show w'. This program is free software, and you are welcome to redistribute it under certain conditions; type `,show c' for details. Enter `,help' for help. scheme@(guile-user)> (use-modules (json)) scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.635275s real time, 11.126605s run time. 5.119203s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.856995s real time, 12.605237s run time. 6.476064s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.556502s real time, 10.542702s run time. 4.550531s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.396581s real time, 9.638931s run time. 3.707881s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.293497s real time, 8.944718s run time. 3.055733s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.249073s real time, 8.938264s run time. 3.099037s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.168000s real time, 8.557252s run time. 2.772902s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.206124s real time, 7.920464s run time. 2.022655s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.404214s real time, 8.412361s run time. 2.402077s spent in GC. And actually Guile 3.0.2 seems a bit slower at the beginning but then for some reason times go down until they seem to stabilize (I have tried it a couple of times and it does the same) and then it seems a bit faster than 2.2.7: # ./env guile GNU Guile 3.0.2 Copyright (C) 1995-2020 Free Software Foundation, Inc. Guile comes with ABSOLUTELY NO WARRANTY; for details type `,show w'. This program is free software, and you are welcome to redistribute it under certain conditions; type `,show c' for details. Enter `,help' for help. scheme@(guile-user)> (use-modules (json)) scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.961477s real time, 6.973492s run time. 2.294030s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 7.450862s real time, 7.422345s run time. 2.718710s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.438989s real time, 6.399829s run time. 1.896063s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 6.097962s real time, 6.070055s run time. 1.540690s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 5.650008s real time, 5.668240s run time. 1.272017s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 5.754515s real time, 5.748386s run time. 1.275179s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 5.760096s real time, 5.755418s run time. 1.310558s spent in GC. scheme@(guile-user)> ,t (define a (call-with-input-file "large-file.json" (lambda (port) (json->scm port)))) ;; 5.745274s real time, 5.739386s run time. 1.356917s spent in GC. Let me know if you want me to test anything else. > Thanks in advance! > > Thank you! Aleix