bug#14518: C and Emacs Lisp code parts

bug#14518: C and Emacs Lisp code parts

[Andreas Röhler]

On 06.07.2016 00:48, John Wiegley wrote:
>>>>>> Eli Zaretskii <eliz@gnu.org> writes:
>> In which you were asked to provide some numbers, but gave none. Please do
>> provide them, and perhaps that bug could be taken care of.
> Until we have numbers, no action will be taken here. I am still of the
> position that *more* code should be moved from C to Emacs Lisp, and not the
> other way around.
>
> If there are cases where this might be a bad idea, measurement is needed to
> convince me. As others have said, performance is a complex beast, and human
> guesses about how a modern machine operates are more often wrong than not.
>

M-x elp-instrument-function RET define-abbrevs RET
do some edits
M-x elp-results RET


abbrev--describe               36050       15.224345396 0.0004223119
abbrev-edit-save-buffer        1           8.034011581   8.034011581
abbrev-edit-save-to-file       1           8.033998314   8.033998314
abbrev--write                  18025       5.8414600190 0.0003240754
define-abbrevs                 1           1.334075568   1.334075568
abbrev-get                     107835      0.5151135200 4.776...e-06
abbrev-table-get               36964       0.1173239610 3.174...e-06
abbrev-table-put               18320       0.0690998279 3.771...e-06
abbrev-table-empty-p           584         0.010703864 1.832...e-05
abbrev-table-p                 584         0.0050513859 8.649...e-06
abbreviate-file-name           91          0.002899625 3.186...e-05
abbrev-table-name              2           0.000254252   0.000127126
abbrev-mode                    1           1.4463e-05    1.4463e-05

bug#14518: C and Emacs Lisp code parts

[Noam Postavsky]

On Wed, Jul 6, 2016 at 3:25 AM, Andreas Röhler
<andreas.roehler@online.de> wrote:
> M-x elp-instrument-function RET define-abbrevs RET
> do some edits
> M-x elp-results RET
>
>
> abbrev--describe               36050       15.224345396 0.0004223119
> abbrev-edit-save-buffer        1           8.034011581   8.034011581
> abbrev-edit-save-to-file       1           8.033998314   8.033998314
> abbrev--write                  18025       5.8414600190 0.0003240754
> define-abbrevs                 1           1.334075568   1.334075568
> abbrev-get                     107835      0.5151135200 4.776...e-06
> abbrev-table-get               36964       0.1173239610 3.174...e-06
> abbrev-table-put               18320       0.0690998279 3.771...e-06
> abbrev-table-empty-p           584         0.010703864 1.832...e-05
> abbrev-table-p                 584         0.0050513859 8.649...e-06
> abbreviate-file-name           91          0.002899625 3.186...e-05
> abbrev-table-name              2           0.000254252   0.000127126
> abbrev-mode                    1           1.4463e-05    1.4463e-05
>
>

I think you left out some steps. I tried modifying Glen's test above
to give approximately the same number of abbrevs

;; 17576 abbrevs
(dotimes (i 26)
  (dotimes (j 26)
    (dotimes (k 26)
      (define-abbrev emacs-lisp-mode-abbrev-table
      (concat (char-to-string (+ 97 i))
              (char-to-string (+ 97 j))
                    (char-to-string (+ 97 k)))
      "who cares"))))

M-x elp-instrument-package RET abbrevs RET
M-x edit-abbrevs RET
SPC DEL C-x C-s
M-x elp-results

abbrev-edit-save-to-file  1           0.687         0.687
abbrev-edit-save-buffer   1           0.687         0.687
abbrev--write             17578       0.2720000000  1.54...e-005
abbrev--describe          17578       0.2540000000  1.44...e-005
abbrev-table-get          17633       0.0420000000  2.38...e-006
abbrev-get                70312       0.0390000000  5.54...e-007
abbrev-table-put          17605       0.0340000000  1.93...e-006
abbrev-table-p            27          0.0           0.0
abbrev-table-name         1           0.0           0.0
abbrev-table-empty-p      27          0.0           0.0

GNU Emacs 24.5.1 (i686-pc-mingw32) of 2015-04-11 on LEG570

bug#14518: C and Emacs Lisp code parts

[Eli Zaretskii]

[Please don't cross-post between the bug list and emacs-deve.]

> From: Andreas Röhler <andreas.roehler@online.de>
> Date: Wed, 6 Jul 2016 09:25:54 +0200
> Cc: Eli Zaretskii <eliz@gnu.org>
> 
> abbrev--describe               36050       15.224345396 0.0004223119
> abbrev-edit-save-buffer        1           8.034011581   8.034011581
> abbrev-edit-save-to-file       1           8.033998314   8.033998314
> abbrev--write                  18025       5.8414600190 0.0003240754
> define-abbrevs                 1           1.334075568   1.334075568
> abbrev-get                     107835      0.5151135200 4.776...e-06
> abbrev-table-get               36964       0.1173239610 3.174...e-06
> abbrev-table-put               18320       0.0690998279 3.771...e-06
> abbrev-table-empty-p           584         0.010703864 1.832...e-05
> abbrev-table-p                 584         0.0050513859 8.649...e-06
> abbreviate-file-name           91          0.002899625 3.186...e-05
> abbrev-table-name              2           0.000254252   0.000127126
> abbrev-mode                    1           1.4463e-05    1.4463e-05

Thanks.

It is better to use profiler.el, because it doesn't change the code
being profiled, and also can profile primitives.  If you can produce a
profile using profiler.el, and present it in fully expanded form,
please do.

Also, I'm not sure how to read the above (and the elp documentation
doesn't really help).  What was the total elapsed time it took to run
this scenario?  Is it the sum of all the numbers in the first column,
i.e. about 37 sec?  Or does the elapsed time for each function include
all of its callers?  Either way, the numbers look strange: why did it
take abbrev-edit-save-to-file, whose body is almost empty, 8 sec,
whereas abbrev--describe took 15 sec?  What am I missing?

Anyway, I looked at the v22 C implementation of the relevant
functions, and I see that the Lisp implementation is essentially
identical to C.  For example, here's the Lisp implementation of
abbrev--describe:

  (defun abbrev--describe (sym)
    (when (symbol-value sym)
      (prin1 (symbol-name sym))
      (if (null (abbrev-get sym :system))
	  (indent-to 15 1)
	(insert " (sys)")
	(indent-to 20 1))
      (prin1 (abbrev-get sym :count))
      (indent-to 20 1)
      (prin1 (symbol-value sym))
      (when (symbol-function sym)
	(indent-to 45 1)
	(prin1 (symbol-function sym)))
      (terpri)))

and here's what we had in Emacs 22:

  static void
  describe_abbrev (sym, stream)
       Lisp_Object sym, stream;
  {
    Lisp_Object one, count, system_flag;

    if (INTEGERP (XSYMBOL (sym)->plist))
      {
	count = XSYMBOL (sym)->plist;
	system_flag = Qnil;
      }
    else
      {
	count = Fget (sym, Qcount);
	system_flag = Fget (sym, Qsystem_type);
      }

    if (NILP (SYMBOL_VALUE (sym)))
      return;

    one = make_number (1);
    Fprin1 (Fsymbol_name (sym), stream);

    if (!NILP (system_flag))
      {
	insert_string (" (sys)");
	Findent_to (make_number (20), one);
      }
    else
      Findent_to (make_number (15), one);

    Fprin1 (count, stream);
    Findent_to (make_number (20), one);
    Fprin1 (SYMBOL_VALUE (sym), stream);
    if (!NILP (XSYMBOL (sym)->function))
      {
	Findent_to (make_number (45), one);
	Fprin1 (XSYMBOL (sym)->function, stream);
      }
    Fterpri (stream);
  }

As you see, both versions call the same primitives and do little
else.

I see the same basic picture with all the functions which are hot
spots according to the elp profile.  So if indeed the Lisp version is
significantly slower, the only way I can explain that is that we have
some very basic inefficiency in the byte-code interpreter, something
that, if true, is completely unrelated to abbrev.el itself.

So please do the same as you did here with Emacs 22.3, and with the
same abbrevs list, and tell how much elapsed time this takes on the
same system.  We should anyway analyze this comparatively, not in
absolute terms.  (Alternatively, post here the list of the abbrevs you
used in your experiment, then others could do these measurements,
compare them, and maybe provide more information/investigate deeper.)

Thanks.

bug#14518: abbrev edits - delay when saving

[Andreas Röhler]

With more than thousand abbrevs in Emacs Lisp mode, saving it after edits causes a delay of several seconds where Emacs looks blocked.

Thanks all,

Andreas

GNU Emacs 24.3.1 (i686-pc-linux-gnu, GTK+ Version 2.24.14) of 2013-03-05

bug#14518: abbrev edits - delay when saving

[Leo Liu]

On 2013-05-31 17:30 +0800, Andreas Röhler wrote:
> With more than thousand abbrevs in Emacs Lisp mode, saving it after
> edits causes a delay of several seconds where Emacs looks blocked.
>
> Thanks all,
>
> Andreas
>
> GNU Emacs 24.3.1 (i686-pc-linux-gnu, GTK+ Version 2.24.14) of 2013-03-05

Would be nice to have the data to test out the slowdown. At the minimal
maybe give the result from elp-instrument-package.

Leo

bug#14518: abbrev edits - delay when saving

[Andreas Röhler]

Am 01.06.2013 05:01, schrieb Leo Liu:
> On 2013-05-31 17:30 +0800, Andreas Röhler wrote:
>> With more than thousand abbrevs in Emacs Lisp mode, saving it after
>> edits causes a delay of several seconds where Emacs looks blocked.
>>
>> Thanks all,
>>
>> Andreas
>>
>> GNU Emacs 24.3.1 (i686-pc-linux-gnu, GTK+ Version 2.24.14) of 2013-03-05
>
> Would be nice to have the data to test out the slowdown. At the minimal
> maybe give the result from elp-instrument-package.
>
> Leo
>

Hi Leo,

I'll look for that, thanks taking care.

Also the size of abbrev-file might be of interest, it's above 600Kb.

Last time looked into, Emacs would re-compose all abbrev-tables, thus the slow.

Solution might be a kind of abbrev-edits-change watch, which would re-calculate only the table(s) which need this.

Cheers,

Andreas

bug#14518: abbrev edits - delay when saving

[Andreas Röhler]

Am 01.06.2013 05:01, schrieb Leo Liu:
> On 2013-05-31 17:30 +0800, Andreas Röhler wrote:
>> With more than thousand abbrevs in Emacs Lisp mode, saving it after
>> edits causes a delay of several seconds where Emacs looks blocked.
>>
>> Thanks all,
>>
>> Andreas
>>
>> GNU Emacs 24.3.1 (i686-pc-linux-gnu, GTK+ Version 2.24.14) of 2013-03-05
>
> Would be nice to have the data to test out the slowdown. At the minimal
> maybe give the result from elp-instrument-package.
>
> Leo
>

elp-instrument-package is an interactive autoloaded
Lisp function in `elp.el'.

(elp-instrument-package PREFIX)

Instrument for profiling, all functions which start with PREFIX.
For example, to instrument all ELP functions, do the following:

     M-x elp-instrument-package RET elp- RET

;;;;;;;

No idea how to use this WRT abbrev-mode :(

bug#14518: abbrev edits - delay when saving

[Stefan Monnier]

>>> With more than thousand abbrevs in Emacs Lisp mode, saving it after
>>> edits causes a delay of several seconds where Emacs looks blocked.
>> Would be nice to have the data to test out the slowdown.  At the minimal
>> maybe give the result from elp-instrument-package.

Or M-x profiler-start RET  ...  M-x profiler-report RET
which is a bit easier to use.


        Stefan

bug#14518: abbrev edits - delay when saving

[Glenn Morris]

What is the point of having 1000+ abbrevs?
How can you possibly remember them?

bug#14518: abbrev edits - delay when saving

[Andreas Röhler]

Am 05.06.2013 19:02, schrieb Glenn Morris:
>
> What is the point of having 1000+ abbrevs?
> How can you possibly remember them?
>
>
>
>

Often beginning of words composes the abbrev, or it's stored in an other mnemonic way,
for example

     ("pbos" "(py-beginning-of-statement)" nil 36)
     ("pbosp" "(py-beginning-of-statement-p)" nil 2)
     ("pbs" "(py-backward-statement)" nil 2)
     ("pc" "(purecopy" nil 1)
     ("pcb" "(py-close-base" nil 1)
     ("pcf" "py-complete-function" nil 3)
     ("pci" "(py-compute-indentation)" nil 17)
     ("pcioo" "(py-compute-indentation orig origline closing line inside repeat)" nil 1)
     ("pcl" "(py-count-lines)" nil 8)
     ("pclo" "(< (py-count-lines) origline)" nil 1)
     ("pco" "(py-compute-indentation orig origline closing line inside repeat)" nil 2)
     ("pcoo" "(eq (py-count-lines) origline)" nil 1)
     ("pcs" "(py-choose-shell)" nil 4)
     ("pdc" "(py-beginning-of-def-or-class)" nil 0)

Some abbrevs are never used, as the last one here - in exchange many terms have more than one abbrev.

bug#14518: abbrev edits - delay when saving

[Glenn Morris]

;; 1352 abbrevs
(dotimes (i 2) 
  (dotimes (j 26)
    (dotimes (k 26)
      (define-abbrev emacs-lisp-mode-abbrev-table
      (concat (char-to-string (+ 97 i))
              (char-to-string (+ 97 j))
                    (char-to-string (+ 97 k)))
      "who cares"))))

M-x write-abbrev-file  ; takes no measurable time for me

bug#14518: abbrev edits - delay when saving

[Andreas Röhler]

Am 07.06.2013 03:43, schrieb Glenn Morris:
>
> ;; 1352 abbrevs
> (dotimes (i 2)
>    (dotimes (j 26)
>      (dotimes (k 26)
>        (define-abbrev emacs-lisp-mode-abbrev-table
>        (concat (char-to-string (+ 97 i))
>                (char-to-string (+ 97 j))
>                      (char-to-string (+ 97 k)))
>        "who cares"))))
>
> M-x write-abbrev-file  ; takes no measurable time for me
>
>
>
>

Going to EOB in abbrev file, line number shows "17870". Maybe that makes a diff?
BTW some modes seem to copy abbrev-table. Smarter inheritance seems feasible. Which should also affect write-times.

bug#14518: abbrev edits - delay when saving

[Glenn Morris]

Andreas Röhler wrote:

> BTW some modes seem to copy abbrev-table. Smarter inheritance seems
> feasible.

I have no idea what that means, but suspect your problems are specific
to your own idiosyncratic usage.

bug#14518: abbrev edits - delay when saving

[Andreas Röhler]

Am 07.06.2013 09:13, schrieb Glenn Morris:
> Andreas Röhler wrote:
>
>> BTW some modes seem to copy abbrev-table. Smarter inheritance seems
>> feasible.
>
> I have no idea what that means,

When a table inherits abbrevs, it must not copy abbrevs, but read them in parents table.

  but suspect your problems are specific
> to your own idiosyncratic usage.
>
>
>
>

bug#14518: C and Emacs Lisp code parts

[Glenn Morris]

IMO we should simply say: no, abbrevs will not move back to C.
This discussion is not productive. We don't have to exhaustively debunk
every strange suggestion that gets made. That's all I have to say on this.

bug#14518: C and Emacs Lisp code parts

[Eli Zaretskii]

> From: Glenn Morris <rgm@gnu.org>
> Cc: Andreas Röhler <andreas.roehler@online.de>,
>   14518@debbugs.gnu.org
> Date: Wed, 06 Jul 2016 11:44:32 -0400
> 
> IMO we should simply say: no, abbrevs will not move back to C.

We probably will.  But the data presented by Andreas is strange, and I
think warrants at least a bit looking into.  Who knows what we will
find?

bug#14518: C and Emacs Lisp code parts

[John Wiegley]

>>>>> Eli Zaretskii <eliz@gnu.org> writes:

>> IMO we should simply say: no, abbrevs will not move back to C.

> We probably will. But the data presented by Andreas is strange, and I think
> warrants at least a bit looking into. Who knows what we will find?

Agreed.  Andreas' problems may not even be a problem with abbrevs at all, but
I'd very much like to know what is going on.

Andreas, your .abbrev file doesn't live on an NFS mount or something crazy,
does it? :)

-- 
John Wiegley                  GPG fingerprint = 4710 CF98 AF9B 327B B80F
http://newartisans.com                          60E1 46C4 BD1A 7AC1 4BA2

bug#14518: C and Emacs Lisp code parts

[Andreas Röhler]

On 07.07.2016 00:36, John Wiegley wrote:
>>>>>> Eli Zaretskii <eliz@gnu.org> writes:
>>> IMO we should simply say: no, abbrevs will not move back to C.
>> We probably will. But the data presented by Andreas is strange, and I think
>> warrants at least a bit looking into. Who knows what we will find?
> Agreed.  Andreas' problems may not even be a problem with abbrevs at all, but
> I'd very much like to know what is going on.
>
> Andreas, your .abbrev file doesn't live on an NFS mount or something crazy,
> does it? :)
>

Hi all,

nice seeing you disposed to query alternatives too, really appreciate that.

IMHO in the case given the reasons are pretty simple. See for example in

'prepare-abbrev-list-buffer':
...
       (dolist (table abbrev-table-name-list)

Such happens not only there. With the number of active modes/tables it 
growths - maybe exponentially?

Also: why define-abbrevs must process the whole buffer? Why not deal 
with just the changed parts?
Seems no hubble needed so far ;)

Cheers,

Andreas

bug#14518: C and Emacs Lisp code parts

[Eli Zaretskii]

> From: Andreas Röhler <andreas.roehler@easy-emacs.de>
> Cc: Eli Zaretskii <eliz@gnu.org>, John Wiegley <johnw@gnu.org>
> Date: Thu, 7 Jul 2016 09:33:12 +0200
> 
> IMHO in the case given the reasons are pretty simple. See for example in
> 
> 'prepare-abbrev-list-buffer':
> ...
>       (dolist (table abbrev-table-name-list)
> 
> Such happens not only there. With the number of active modes/tables it growths - maybe exponentially?
> 
> Also: why define-abbrevs must process the whole buffer? Why not deal with just the changed parts?

(This is no longer about C vs Lisp, right?)

If you want to propose changes in abbrevs.el whose purpose is to speed
it up, please do.  But please also include with the changes the
rationale in the form of timing measurements, so that, if the code
becomes more complicated as result, we could judge the speed-up
against the added complexity.

Thanks.

bug#14518: C and Emacs Lisp code parts

[Andreas Röhler]

On 06.07.2016 17:44, Glenn Morris wrote:
> IMO we should simply say: no, abbrevs will not move back to C.

A better approach might be to ask: Why does it take so long? Are there 
ways to solve the task in a shorter time? Such questions are quite 
before any Lisp/C discussion.

bug#14518: C and Emacs Lisp code parts

[Eli Zaretskii]

> From: Andreas Röhler <andreas.roehler@easy-emacs.de>
> Date: Wed, 6 Jul 2016 18:21:03 +0200
> 
> A better approach might be to ask: Why does it take so long?

I did.  As of now, I don't understand the data you presented, so I
asked for some more.

bug#14518: C and Emacs Lisp code parts

[Andreas Röhler]

On 06.07.2016 18:37, Eli Zaretskii wrote:
>> From: Andreas Röhler <andreas.roehler@easy-emacs.de>
>> Date: Wed, 6 Jul 2016 18:21:03 +0200
>>
>> A better approach might be to ask: Why does it take so long?
> I did.  As of now, I don't understand the data you presented, so I
> asked for some more.

Hi Eli,

.abbrev_defs here counts 18415 lines. Can't post it as such, as it may 
contain private data.
AFAIU the slowness is result of a proceeding, which reads/writes all 
available abbrev tables.

A solution would restrict that read/write to mode-abbrev table at stake, 
or better to single abbrev edited.
Maybe edit-abbrev should be changed into edit-all-abbrev-at-once - but 
discouraged.

Thanks,

Andreas

bug#14518: C and Emacs Lisp code parts

[Eli Zaretskii]

> Cc: 14518@debbugs.gnu.org
> From: Andreas Röhler <andreas.roehler@easy-emacs.de>
> Date: Wed, 6 Jul 2016 19:27:24 +0200
> 
> .abbrev_defs here counts 18415 lines. Can't post it as such, as it may 
> contain private data.

OK, but then please collect the additional data I asked for, and post
that.  It might give us some clues.

> AFAIU the slowness is result of a proceeding, which reads/writes all 
> available abbrev tables.

It is too slow.  37 sec to write 18K strings is unbelievably slow with
today's machines.  Glenn presented a similar scenario with a very
similar number of abbrevs, which is 2 orders of magnitude faster.  So
there's something at work here that we need to understand, because my
gut feeling is that it is not directly related to abbrevs.el or Lisp
vs C in general.

> A solution would restrict that read/write to mode-abbrev table at stake, 
> or better to single abbrev edited.
> Maybe edit-abbrev should be changed into edit-all-abbrev-at-once - but 
> discouraged.

IME, it is not a good idea to discuss solutions before the problem is
sufficiently understood.  We are not there yet.  Let's analyze this
some more.

Thanks.

bug#14518: Status: abbrev edits - delay when saving

[npostavs]

tag moreinfo unreproducible
quit

As already mentioned by Eli
(http://debbugs.gnu.org/cgi/bugreport.cgi?bug=14518#46), we need an
example with public data, or at the very least some timings comparing
slow and fast runs.  As it stands, there is no way to make progress on
this bug.

bug#14518: Status: abbrev edits - delay when saving

[Glenn Morris]

npostavs@users.sourceforge.net wrote:

> As already mentioned by Eli
> (http://debbugs.gnu.org/cgi/bugreport.cgi?bug=14518#46), we need an
> example with public data, or at the very least some timings comparing
> slow and fast runs.  As it stands, there is no way to make progress on
> this bug.

I'm convinced this report isn't going to lead anywhere, so am closing it.
It is just a sink for developer time.

bug#14518: C and Emacs Lisp code parts

[Phillip Lord]

Andreas Röhler <andreas.roehler@online.de> writes:

> On 06.07.2016 00:48, John Wiegley wrote:
>>>>>>> Eli Zaretskii <eliz@gnu.org> writes:
>>> In which you were asked to provide some numbers, but gave none. Please do
>>> provide them, and perhaps that bug could be taken care of.
>> Until we have numbers, no action will be taken here. I am still of the
>> position that *more* code should be moved from C to Emacs Lisp, and not the
>> other way around.
>>
>> If there are cases where this might be a bad idea, measurement is needed to
>> convince me. As others have said, performance is a complex beast, and human
>> guesses about how a modern machine operates are more often wrong than not.
>>
>
> M-x elp-instrument-function RET define-abbrevs RET
> do some edits
> M-x elp-results RET
>
>
> abbrev--describe               36050       15.224345396 0.0004223119
> abbrev-edit-save-buffer        1           8.034011581   8.034011581
> abbrev-edit-save-to-file       1           8.033998314   8.033998314
> abbrev--write                  18025       5.8414600190 0.0003240754
> define-abbrevs                 1           1.334075568   1.334075568
> abbrev-get                     107835      0.5151135200 4.776...e-06
> abbrev-table-get               36964       0.1173239610 3.174...e-06
> abbrev-table-put               18320       0.0690998279 3.771...e-06
> abbrev-table-empty-p           584         0.010703864 1.832...e-05
> abbrev-table-p                 584         0.0050513859 8.649...e-06
> abbreviate-file-name           91          0.002899625 3.186...e-05
> abbrev-table-name              2           0.000254252   0.000127126


But what do these numbers mean? Is this better or worse than previously,
and what are you saving?

Phil