Re: [PERFORMANCE] Why some org code is so deep invoked?

["Christopher M. Miles" <numbchild@gmail.com>]

[-- Attachment #1.1: Type: text/plain, Size: 2118 bytes --]


Ihor Radchenko <yantar92@gmail.com> writes:

> "Christopher M. Miles" <numbchild@gmail.com> writes:
>
>>> I do not see much issue with deep nesting of the code.
>>
>> Is this deep nested code normal in Emacs Lisp?
>>
>> Usually (based on my less than 20 times profiling experience), Emacs
>> wouldn't have deeper code than 40 levels. But my attachment profiler
>> report has more than 100 levels.
>>
>> If this is normal and fine, It's OK. I repeat, I ask this question for
>> curious purpose which want to get an answer for not important question.
>
> It depends. You are looking at the complex code here, which is not
> necessarily common.
>
> However, lisp nesting is tangent to performance. Shallow nesting can be
> slow while deep nesting can be fast. Or vice versa.
>
I see, thanks for answering.

>>> Could you please clarify what exactly is your problem?
>>> Is agenda generation slow?
>>
>> From the profiler report, you can see that Agenda is slow on clock table
>> generation because I have ~org-agenda-start-with-clockreport-mode~
>> enabled. And this deep code invocation is from it too. It's about 5
>> seconds to generate the org-agenda clock table. Actually I can tolerate
>> this time, Just found this performance issue when profiling and curious
>> to ask this question.
>
> Note that your profiler result does not look like taken from a 5
> second-lasting code:
>
>          390  13%     - completing-read
>
> Completing read takes >10% *CPU time* of the 5 seconds? Suspicious. I'd
> retry to get the profile.

I re-profiled three times, around 4 seconds.

>
> Also, I suggest to use M-x write-file in the profiler buffer when
> sharing something as deeply nested as you got. The resulting file is
> much more comfortable to view - it will preserve all the actual profiler
> data.

I see, I tried it, it indeed kept the profiler data!

>
> I will refrain from trying to deduce anything from the profiler for now.
>
> Please try to reproduce the report again and share it with us. Then, I
> will try to see if we can do anything on the Org side.

Ok, I attached the new generated profiler reports.


[-- Attachment #1.2: profiler-cpu-report-2.log --]
[-- Type: text/plain, Size: 152 bytes --]

        1284  57% + command-execute
         935  41% + ...
          21   0% + timer-event-handler
           2   0% + redisplay_internal (C function)

[-- Attachment #1.3: profiler-memory-report-2.log --]
[-- Type: text/plain, Size: 2528 bytes --]

    410,957,330  97% - command-execute
    410,957,330  97%  - call-interactively
    405,537,622  95%   - funcall-interactively
    331,652,432  78%    - org-agenda-redo-all
    331,652,432  78%     - if
    331,651,376  78%      - org-agenda-redo
    331,651,376  78%       - let*
    331,649,112  78%        - if
    331,649,112  78%         - progn
    331,649,112  78%          - let*
    331,649,112  78%           - eval
    331,649,112  78%            - let
    331,649,112  78%             - funcall
    331,649,112  78%              - #<lambda -0x196502c669cdd461>
    331,649,112  78%               - eval
    331,649,112  78%                - org-agenda-list
    331,649,112  78%                 - catch
    299,277,191  70%                  - let*
    213,251,714  50%                   - if
    213,105,362  50%                    - progn
    213,105,362  50%                     - let
    212,941,062  50%                      - setq
    212,940,006  50%                       - apply
    212,940,006  50%                        - org-clock-get-clocktable
    212,940,006  50%                         + let
          1,056   0%                       + org-plist-delete
        124,712   0%                      + org-agenda-files
         16,584   0%                        insert
          7,764   0%                      + if
         58,632   0%                    + or
         19,576   0%                    + if
          3,136   0%                    + let*
     78,430,580  18%                   + while
      7,306,892   1%                   + org-agenda-finalize
        148,040   0%                     add-text-properties
        139,819   0%                   + org-agenda-files
             48   0%                   + org-today
     32,366,705   7%                  + org-agenda-prepare
          4,160   0%                  + org-compile-prefix-format
          1,024   0%        + or
          1,056   0%      + turn-on-ligature-mode
     35,958,904   8%    + eyebrowse-create-window-config
     30,440,458   7%    + org-agenda
      6,646,049   1%      delete-window
        839,779   0%    + execute-extended-command
      5,419,708   1%   + byte-code
     11,917,712   2% + redisplay_internal (C function)
        280,655   0% + ...
          1,984   0% + timer-event-handler
          1,152   0% + corfu--auto-post-command
             80   0%   flyspell-post-command-hook
             80   0% + indent-guide-pre-command-hook
             80   0% + flycheck-maybe-display-error-at-point-soon

[-- Attachment #1.4: Type: text/plain, Size: 269 bytes --]



-- 

[ stardiviner ]
I try to make every word tell the meaning that I want to express without misunderstanding.

Blog: https://stardiviner.github.io/
IRC(libera.chat, freenode): stardiviner, Matrix: stardiviner
GPG: F09F650D7D674819892591401B5DF1C95AE89AC3

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 487 bytes --]