Re: Guile's time execution issues

[Linus Björnstam]

Hi Aleix

Try throwing the result of json->SCM away: (let ((a (call-with...))) 1). Then 
you can run a (gc) between runs. If the GC time increases then, maybe guile 
cannot release the memory?? I don't know, but there is some shared substring 
thing going on in guile, even though I think string-append doesn't do that.

Nice to see that my suggestions worked!
-- 
  Linus Björnstam

On Wed, 22 Apr 2020, at 00:03, Aleix Conchillo Flaqué wrote:
> Hi,
> 
> I was trying to get some guile-json performance times loading large 
> JSON 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.
> 
> The good news is that I have applied a suggestion from Linus Björnstam 
> that reduces times by half (considering the first run above). The 
> suggestion was to use string ports instead of string-append. And 
> interestingly this time, time executions remain around the same value:
> 
> scheme@(guile-user)> ,t (define a (call-with-input-file 
> "/Users/aleix/Downloads/large-file.json" (lambda (port) (json->scm 
> port))))
> ;; 9.099597s real time, 17.239176s run time. 9.309819s spent in GC.
> ;; 9.927868s real time, 20.855859s run time. 12.528727s spent in GC.
> ;; 8.981248s real time, 15.043991s run time. 7.050269s spent in GC.
> ;; 9.055893s real time, 15.400981s run time. 7.383187s spent in GC.
> ;; 9.055850s real time, 15.261824s run time. 7.239188s spent in GC.
> ;; 9.315239s real time, 15.231889s run time. 7.005570s spent in GC.
> ;; 9.106168s real time, 14.987678s run time. 6.915028s spent in GC.
> ;; 9.175142s real time, 14.471324s run time. 6.302749s spent in GC.
> ;; 8.966537s real time, 14.400318s run time. 6.412858s spent in GC.
> 
> JSON test data obtained from:
> 
> https://github.com/json-iterator/test-data/blob/master/large-file.json
> 
> Best,
> 
> Aleix