[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: profiler-report seems to be missing data?
From: |
Charlie Andrews |
Subject: |
Re: profiler-report seems to be missing data? |
Date: |
Fri, 17 Aug 2018 11:36:03 -0400 |
Byte compiling the file didn't seem to have much effect: let* was still
blamed for the vast majority of the runtime (57%). I verified that the
byte compiled version was the one loaded with M-x locate-library, which
returned the .elc version of the library.
Eliminating the let* by inlining its intermediate variables led to
interesting results:
- command-execute 1737 92%
- call-interactively 1737 92%
- apply 1737 92%
- call-interactively@ido-cr+-record-current-command 1737
92%
- apply 1737 92%
- #<subr call-interactively> 1737 92%
- funcall-interactively 1737 92%
- ftf-find-file 1732 92%
- ftf-project-files-alist 1641 87%
- ftf-project-files-hash 1425 75%
- let* 1425 75%
- mapcar 1112 59%
- #<lambda 0x3601f12d> 1104 58%
- puthash 1092 58%
- cons 884 47%
gethash 188 10%
+ split-string 265 14%
+ maphash 212 11%
+ ido-completing-read 83 4%
mapcar 4 0%
+ profiler-report 5 0%
+ ... 138 7%
+ timer-event-handler 1 0%
The interesting parts here:
- The overall number of CPU samples didn't change, I think indicating
that eliminating the let* didn't in fact speed up the code. (In both cases,
I ran ftf-find-file once, which took 4-5 seconds.)
- The samples that were originally blamed on let* are instead blamed
largely on cons and gethash now, which in my opinion seems more likely
My suspicion here is that let* and the profiler are having some bad
interaction where the samples are incorrectly being attributed to let* when
they should be instead attributed to code called within the let*. Stefan,
do you think I'm interpreting this correctly?
On Thu, Aug 16, 2018 at 6:47 PM Stefan Monnier <monnier@iro.umontreal.ca>
wrote:
> > I'm trying to profile the usually excellent `find-things-fast` package to
> > figure out why it's slow in my project.
>
> The presence of `let*` in the profile indicates that the code is not
> byte-compiled. The difference in performance when byte-compiled can be
> large enough, so I'd suggest you first byte-compile your code and only
> then would I recommend you profile it (if still needed).
>
> > - #<lambda 0x5458e8e0>
> 1024 51%
> > - let*
> 1008 50%
> > cons
> 24 1%
>
> This suggests that a lot of time is spent in `let*` which may simply be
> because #<lambda 0x5458e8e0> is called many many times and doesn't do
> much more than `let*`.
>
> Looking at your function, I'm indeed surprised that even tough this
> `let*` was found 1008 times none of those times also found
> file-name-nondirectory or expand-file-name or gethash in the stack.
>
> Maybe this hints at a bug in the profiler code. Can you try and run
> this code many more times, so as to increase the "1008" to a larger
> number, making it yet more statistically unlikely that none of
> file-name-nondirectory or expand-file-name or gethash are found?
>
>
> Stefan
>
>
>
- Re: profiler-report seems to be missing data?, (continued)
- Re: profiler-report seems to be missing data?, Eli Zaretskii, 2018/08/16
- Re: profiler-report seems to be missing data?, Michael Heerdegen, 2018/08/16
- Re: profiler-report seems to be missing data?, Charlie Andrews, 2018/08/16
- Re: profiler-report seems to be missing data?, Eli Zaretskii, 2018/08/16
- Re: profiler-report seems to be missing data?, Charlie Andrews, 2018/08/16
- Re: profiler-report seems to be missing data?, Eli Zaretskii, 2018/08/16
- Re: profiler-report seems to be missing data?, Michael Heerdegen, 2018/08/16
- Re: profiler-report seems to be missing data?, Eli Zaretskii, 2018/08/16
- Re: profiler-report seems to be missing data?, Michael Heerdegen, 2018/08/16
Re: profiler-report seems to be missing data?, Stefan Monnier, 2018/08/16
- Re: profiler-report seems to be missing data?,
Charlie Andrews <=