Re: LilyPond 2.23.6 released

[Luca Fascione]

Hi Thomas,

maybe this can be handy: the `moreutils` package has a utility called `ts`, that will prepend a timestamp to each line of output.

If you pipe the output of your compilation into it, you can get timing information quite easily, here's an example:

% ls | ts -s "%H:%M:%.S"
00:00:00.000013 _config
00:00:00.000546 myfavoritethings_ob-cm.pdf
00:00:00.000567 myfavoritethings_ob-em.pdf
00:00:00.000580 openbook_v1-1.pdf
00:00:00.000591 openbook_v1.ly
00:00:00.000602 openbook_v1.pdf
00:00:00.000613 src

Here I'm using "-s" to mean "time relative to the start time", and "%.S" in the format to mean "print out subsecond timestamps".

(As your runs are sub-minute, you can probably use "%M:%.S" if you feel like saving some 0's on the left)

You can capture stderr also adding `2>&1` before the pipe, like this: "<yourcommand> 2>&1 | ts ..." 

The moreutils package is installed in Linux distributions but doesn't appear to be there by default on MacOS, 

our friends on stackexchange indicate that on brew you'd use `brew install moreutils` to get the package (I just tried this, it worked fine for me), 

on macports I think it's something like `sudo port install moreutils` (but I don't use macports, so I haven't tested this one).

HTH,

Luca

On Sun, Feb 20, 2022 at 9:26 AM Thomas Scharkowski <t.scharkowski@t-online.de> wrote:

Quick answer: I can notice the speed difference in the terminal output from the very start.
I will try the diff later.
Thomas

> Am 19.02.2022 um 20:12 schrieb Jean Abou Samra <jean@abou-samra.fr>:
>
> Le 19/02/2022 à 16:41, Thomas Scharkowski a écrit :
>> One more test:
>> I installed both versions on a 2013 iMac intel Core i5.
>>
>> 24,3“ MacPorts version
>> 51,4“ gitab version
>
>
> OK, bear with me. Can you please take the following steps
> and report results? It is really important for us to identify
> what is causing this slowdown.
>
> First, does it look like one step of the compilation in particular
> is slow (for example, it takes time during "Preprocessing graphical
> objects"), or do all steps take more time? Pro tip: run lilypond with
> --verbose to have a more fine-grained view of the process.
>
> Second, edit the file lily.scm (should be under
> /path/to/lilypond-2.23.6/share/lilypond/2.23.6/scm/lily)
> to apply the following diff:
>
>
> @@ -844,8 +844,11 @@ PIDs or the number of the process."
>
>  ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
>
> +(use-modules (statprof))
> +
>  (define-public (lilypond-main files)
>    "Entry point for LilyPond."
> +  (statprof (lambda ()
>    (eval-string (ly:command-line-code))
>    (if (ly:get-option 'help)
>        (begin (ly:option-usage)
> @@ -927,7 +930,7 @@ PIDs or the number of the process."
>                 (ly:exit 1 #f))
>          (begin
>            (ly:exit 0 #f)))))
> -
> +))
>  (define-public (session-start-record)
>    (for-each (lambda (v)
>             ;; import all public session variables natively into parser
>
>
>
> Namely, add "(use-modules (statprof))" before the definition of
> lilypond-main, "(statprof (lambda ()" after the line "Entry point
> for LilyPond", and "))" after the function. This makes LilyPond
> run under a profiling tool and report output at the end of the
> compilation. Now run once with GUILE_AUTO_COMPILE=1, to recompile
> lily.scm. The second run will be clean (all files byte-compiled);
> can you report the big list of timings that is printed at the end?
>
> Thanks in advance,
> Jean
>