bugGNU Octave - Bugs: bug #58150, Slow loglog plot with non-default...

 
 

bug #58150: Slow loglog plot with non-default font

Submitter:  Guillaume <gyom>
Submitted:  Thu 09 Apr 2020 09:25:16 PM UTC
   
 
Category:  Plotting with OpenGL Severity:  3 - Normal
Priority:  5 - Normal Item Group:  Performance
Status:  Fixed Assigned to:  None
Originator Name:  Guillaume Open/Closed:  * Closed
Release:  * 6.0.90 Operating System:  * GNU/Linux
Fixed Release:  None Planned Release:  None
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Sat 11 Apr 2020 11:14:00 PM UTC, comment #11: 

I checked the fix in on the stable branch (https://hg.savannah.gnu.org/hgweb/octave/rev/11d66485fc19).  This was a regression of long standing so deserves to be part of the 6.1 release.

Given how pronounced it is, I'm surprised it wasn't noticed earlier.

I used the same test script with some older versions of Octave


4.0.3  :  .06 seconds
4.2.1  :  .45 seconds
4.4.3  :  .49 seconds
5.1.0  : 1.12 seconds
5.2.0  : 1.15 seconds
6.0.90 :  .10 seconds


So, we are now roughly back to what existed with version 4.0.3 which is good.

Marking as fixed and closing report.

Rik <rik5>
Group administrator
Sat 11 Apr 2020 02:27:56 PM UTC, comment #10: 

Thanks Pantxo and Rik. Yes, there was one missing line in comment #3:


            __go_line__: 8 calls, 11.883 total, 11.883 sel


I just tried Pantxo's patch from comment #9 and it seems to fix the issue for me.


>> figure ("DefaultAxesFontName", "*"); tic; loglog (rand (8)); toc
Elapsed time is 0.426529 seconds.
>> figure ("DefaultAxesFontName", "Helvetica"); tic; loglog (rand (8)); toc
Elapsed time is 0.52403 seconds.
>> figure ("DefaultAxesFontName", "Helvetica"); tic; loglog (rand (8)); toc
Elapsed time is 0.436887 seconds.


Thank you!

Guillaume <gyom>
Sat 11 Apr 2020 02:20:10 PM UTC, comment #9: 

The attached patch seems to fix the issue for me.

(file #48814)

Pantxo Diribarne <pantxo>
Group Member
Sat 11 Apr 2020 01:01:05 PM UTC, comment #8: 

We have a font manager that is supposed to cache already loaded fonts. I had already noticed that this did not work so well (at least no as I would expect).

I have added the following printf in order to see when a given font face is erased from the font cache:


diff -r bc6dae9cbe73 libinterp/corefcn/ft-text-renderer.cc
--- a/libinterp/corefcn/ft-text-renderer.cc     Thu Apr 09 15:35:57 2020 -0700
+++ b/libinterp/corefcn/ft-text-renderer.cc     Sat Apr 11 14:25:08 2020 +0200
@@ -412,7 +412,8 @@
       if (face->generic.data)
         {
           ft_key *pkey = reinterpret_cast<ft_key *> (face->generic.data);
-
+          printf ("Destroying font %s\n", pkey->first.c_str ());
+
           cache.erase (*pkey);
           delete pkey;
           face->generic.data = nullptr;


Here is what I observe:


octave:1> figure ();
octave:2> axes (); hold on
octave:3> plot (1:10)
octave:4> cla
octave:5> loglog (1:10)
Destroying font *:normal:normal
Destroying font *:normal:normal
... (50+ times) ...
Destroying font *:normal:normal


From this simple session I can notice the following:

  • If I don't add the "hold on" statement, the cache is cleared for each axes reset/redraw. My conclusion is that for most use case this caching is inefficient: the cache should persist for at least as long as a figure exists (ideally it would persist for an Octave session).
  • after "hold on", a simple "plot" command seems to use cached fonts but log plots feed/free the cache 50+ times



Pantxo Diribarne <pantxo>
Group Member
Sat 11 Apr 2020 12:09:32 AM UTC, comment #7: 

This seems to be related to the number of logarithmic axes.

See running times for various plot functions on my computer:


plot     : 0.14
semilogx : 0.55
semilogy : 0.87
loglog   : 1.20



Rik <rik5>
Group administrator
Sat 11 Apr 2020 12:01:51 AM UTC, comment #6: 

This isn't anything about having to redraw the plot.  I made the figure invisible while plotting and the triggered a redraw of the figure at the end of the sequence and it is still slow.


figure ("DefaultAxesFontName", "Helvetica");
y = rand (8);
set (gcf, 'visible', 'off');
tic; loglog (y); toc
set (gcf, 'visible', 'on');



Rik <rik5>
Group administrator
Fri 10 Apr 2020 11:48:20 PM UTC, comment #5: 

This is very strange.  The call to _go_line_ is

    retval(i) = __go_line__ (hp, "xdata", x, "ydata", y(:,i),
                             "color", color, "linestyle", linestyle,
                             "marker", marker, properties{:});


I put a keyboard() statement before this and checked the value of properties, marker, linestyle, and color and they are the same between the slow version and the fast version.

Somehow, the C++ code must be triggering smoe slowdown.

Rik <rik5>
Group administrator
Fri 10 Apr 2020 11:41:42 PM UTC, comment #4: 

Is there more detail in the profile report?  It still says 12.441 total which means something else is still taking up the majority of the time.  Is it _go_line_ in _plt_>__plt2vm__?

Rik <rik5>
Group administrator
Fri 10 Apr 2020 08:08:41 PM UTC, comment #3: 

I tried fc-cache but I still observe the same thing. It seems to be specific to loglog, i.e. no such difference with plot. A profile report returns this:


  loglog: 1 calls, 13.829 total, 0.000 self
    __plt__: 1 calls, 12.444 total, 0.001 self
      __plt__>__plt1__: 1 calls, 12.442 total, 0.000 self
        __plt__>__plt2__: 1 calls, 12.442 total, 0.000 self
          1) __plt__>__plt2vm__: 1 calls, 12.441 total, 0.002 self


Guillaume <gyom>
Thu 09 Apr 2020 11:37:36 PM UTC, comment #2: 

I see the slow-down as well though my times are 0.1 and 1.1 seconds correspondingly. fc-cache -f does not make any difference.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Thu 09 Apr 2020 11:31:37 PM UTC, comment #1: 

I think this has come up before.

What happens if you re-build the font cache before starting Octave with


fc-cache -f



Rik <rik5>
Group administrator
Thu 09 Apr 2020 09:25:16 PM UTC, original submission:  

Maybe it's an issue with the specific machine I am testing this on but I noticed that a loglog plot becomes very slow when changing the default font:


>> figure ("DefaultAxesFontName", "*"); tic; loglog (rand (8)); toc
Elapsed time is 0.506582 seconds.
>> figure ("DefaultAxesFontName", "Helvetica"); tic; loglog (rand (8)); toc
Elapsed time is 14.1015 seconds.


It doesn't seem to make a difference whether the font is available or not on the machine.

Guillaume <gyom>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #48814:  bug58150.patch added by pantxo (1KiB - text/x-patch)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by pantxo (Posted a comment)
  • -email is unavailable- added by dasergatskov (Posted a comment)
  • -email is unavailable- added by rik5 (Posted a comment)
  • -email is unavailable- added by gyom (Submitted the item)
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only group members can vote.

     

    Follow 6 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2020-04-11 rik5 StatusPatch Submitted Fixed
        Open/ClosedOpen Closed
        Releasedev 6.0.90
    2020-04-11 pantxo Attached File- Added bug58150.patch, #48814
        StatusConfirmed Patch Submitted
    2020-04-11 rik5 StatusNone Confirmed

    Back to the top

    Powered by Savane 3.13-f8d8.
    Corresponding source code