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.scharkow...@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 <j...@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 > > > > >
