bugGNU Octave - Bugs: bug #63646, Long creation times for...

 
 

bug #63646: Long creation times for sparseimages.m in manual due to -svgconvert option to print

Submitter:  Rik <rik5>
Submitted:  Fri 13 Jan 2023 05:39:47 AM UTC
 
Category:  Performance Severity:  3 - Normal
Priority:  5 - Normal Item Group:  Regression
Status:  Fixed Assigned to:  None
Originator Name:  Open/Closed:  * Closed
Release:  * stable Operating System:  * Any
Fixed Release:  8.1.0 (current stable) Planned Release:  8.1.0 (current stable)
* Mandatory Fields

Add a New Comment (Rich Markup)
   

Comment Type & Canned Response:
       

 

( Jump to the original submission )

Wed 01 Feb 2023 03:47:22 PM UTC, comment #37: 
Markus Mützel <mmuetzel>
Project Member
Tue 31 Jan 2023 09:49:34 PM UTC, comment #36: 

Closing report as fixed.

Pantxo Diribarne <pantxo>
Project Member
Tue 31 Jan 2023 08:08:01 PM UTC, comment #35: 

Thank you all for the review.

I pushed it with the proposed modification from comment #33 to the stable branch here:
https://hg.savannah.gnu.org/hgweb/octave/rev/82128f652585

Marking as ready for test.

Markus Mützel <mmuetzel>
Project Member
Tue 31 Jan 2023 12:12:40 AM UTC, comment #34: 

Question: what is supposed to happen with a command like print -nosvgconvert -polymerge-all <filename>? Right now it doesn't signal an error. Is that intended? I'm OK with the behavior either way.

Arun Giridhar <arungiridhar>
Project Member
Mon 30 Jan 2023 09:55:36 PM UTC, comment #33: 

AFAICS, octave_polygon::reconstruct does nothing for reconstruct_level < 2, so we should probably return early
the untouched m_polygon member rather than making a copy of it.

Something like

--- a/src/octave-svgconvert.cc  Mon Jan 30 18:54:27 2023 +0100
+++ b/src/octave-svgconvert.cc  Mon Jan 30 22:38:54 2023 +0100
@@ -165,10 +165,12 @@
   void reset (void)
   { m_polygons.clear (); }

-  QList<QPolygonF> reconstruct ()
+  QList<QPolygonF> reconstruct (int reconstruct_level)
   {
     if (m_polygons.isEmpty ())
       return QList<QPolygonF> ();
+    else if (reconstruct_level < 2)
+      return m_polygons;

Apart from that your patch looks good to me. I can confirm the new default prints much faster when there are no patch or surface in the figure, like in the original example.

Also the example in comment #20 still gives me the same numbers

cla
sombrero (10);
ch = get (gca, "children");
set (ch, "facecolor", "r", "edgecolor", "none")
view (2)
print -nosvgconvert toto_nosvgconvert.svg
print -polymerge toto_svgconvert_base.svg
print toto_svgconvert_all.svg # -polymerge-all, the default
ls -lh toto*

i.e. decreasing file size with increasing level of reconstruction:

...179K Jan 30 22:49 toto_nosvgconvert.svg
...47K Jan 30 22:49 toto_svgconvert_all.svg
...111K Jan 30 22:49 toto_svgconvert_base.svg

Pantxo Diribarne <pantxo>
Project Member
Mon 30 Jan 2023 04:19:18 PM UTC, comment #32: 

Thank you for the review.
The "@options{..}" thing was a typo. I've only tested on Windows where I'm (still) unable to build the documentation. (That part is still untested.)

I noticed a couple of other errors in the documentation.
I removed the default value for the input parameter of that function in octave-svgconvert. I forgot to delete it after some initial incremental changes.

See the attached updated patch.

(file #54289)

Markus Mützel <mmuetzel>
Project Member
Mon 30 Jan 2023 03:41:46 PM UTC, comment #31: 

I could fix it by changing "@options" to "@option" in all locations in the patch. Please check if that is OK.

Arun Giridhar <arungiridhar>
Project Member
Mon 30 Jan 2023 03:36:55 PM UTC, comment #30: 

I'm getting documentation build errors. Is "@options" the same as "@var{options}"? My Texinfo doesn't know how to parse "@options".

Arun Giridhar <arungiridhar>
Project Member
Mon 30 Jan 2023 03:24:27 PM UTC, comment #29: 

@mmuetzel: It looks good overall. A couple of questions:

  • The documentation says that only consecutive polygons are merged by default, not all polygons. Should the line `QList<QPolygonF> reconstruct (int reconstruct_level = 2)` have the default value be 1 instead of 2 to be consistent?
  • Could you change all instances of "subsequent" to "consecutive" for consistency pls?
Arun Giridhar <arungiridhar>
Project Member
Sun 29 Jan 2023 12:11:38 PM UTC, comment #28: 

The attached patch adds the options "-polymerge", "-nopolymerge", and "-polymerge-all" to the print function. These options select whether only subsequent, no, or all polygons that are sharing an edge should be merged into a single polygon when using the SVG toolchain.
By default, only subsequent triangles are merged into a polygon unless the printed figure contains any graphics objects that are of type "patch" or "surface" in which case all polygons sharing an edge are merged (or at least attempted to be merged).

With it, the "spy" example is still about 3 times slower with the (default) svgconvert pipeline than with the eps toolchain for me. But it is about 90 times faster for me with the (new default) "-polymerge" than with the (old default) "-polymerge-all".
I see hardly a performance difference between "-polymerge" and "-nopolymerge" for that example. But the difference in file size is noticeable (about a factor of 3).

Are the names for those new options ok?

(file #54283)

Markus Mützel <mmuetzel>
Project Member
Tue 17 Jan 2023 08:45:06 PM UTC, comment #27: 

Yes, my patch would lie between 1 and 2, but where it falls would be instance-specific, depending on how many polygons are in the same connectedness component as polygon 0. In effect, it only collapses that one component, not all components like level 2, or zero components like level 1. I do not know the expected number of components and their size for general input, so it's tough to give an equivalent level number. For the sombrero example that Pantxo posted in comment #20, it does only some 9 out of 600 possible reductions, but for completely random examples I did, it can do about 1/3.

If we could reorder the polygons based on rough proximity, we could reduce the quadratic search to something like ii-10 <= jj <= i+10, with an N.log(N) sorting step beforehand.

Arun Giridhar <arungiridhar>
Project Member
Tue 17 Jan 2023 05:35:32 PM UTC, comment #26: 

Arun's patch skips step 2 (almost) unconditionally for (almost) everything.

Markus Mützel <mmuetzel>
Project Member
Tue 17 Jan 2023 04:21:00 PM UTC, comment #25: 

Does Arun's patch go beyond 1? If it does should it be
included somewhere between 1 and 2.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 17 Jan 2023 04:14:15 PM UTC, comment #24: 

> the octave_polygon::mergepoly (step 2, the expensive part of the merge job) is only useful for patch and surface objects, so maybe an alternative would be to always apply step 1 and condition step 2 on the option you propose to add.


Sorry. I didn't realize that the "reconstruct" option covered more than the step we were looking at (merging of possible non-consecutive polygons).
Your alternative suggestion of adding an option to skip only the second step (octave_polygon::mergepoly) sounds reasonable to me. Maybe setting "reconstruct" to 2 could be used to select that mode?
Or re-arrange to:
0: no reconstruction
1: basic reconstruction with merging consecutive polygons
2: thorough reconstruction with an attempt to merge as many polygons as possible.

Markus Mützel <mmuetzel>
Project Member
Tue 17 Jan 2023 10:09:47 AM UTC, comment #23: 

@Markus:

>> Would it make sense to use the "reconstruct" option by default only if there are "patch" or "surface" objects in the printed figure?


In the original example there is no such object and the reconstruction is useful (at least for reducing the file size) due to step 1 (merge consecutive triangles).
On the other hand, the octave_polygon::mergepoly (step 2, the expensive part of the merge job) is only useful for patch and surface objects, so maybe an alternative would be to always apply step 1 and condition step 2 on the option you propose to add.

Pantxo Diribarne <pantxo>
Project Member
Tue 17 Jan 2023 09:57:52 AM UTC, comment #22: 

Would it make sense to use the "reconstruct" option by default only if there are "patch" or "surface" objects in the printed figure?
And then have a "reconstruct" or "noreconstruct" option for the print function to allow an end user to force one or the other?

Markus Mützel <mmuetzel>
Project Member
Tue 17 Jan 2023 12:07:03 AM UTC, comment #21: 

In the mergepoly function, instead of copying merged to out and then returning out, like this:

        // Return row vector
        QPolygonF out (merged.size ());
        for (int kk = 0; kk < merged.size (); kk++)
          out[kk] = merged[kk];

        return out;

using "return merged;" is a little faster and does not cause problems for the previous tests. Is that change OK?

Arun Giridhar <arungiridhar>
Project Member
Mon 16 Jan 2023 09:57:51 PM UTC, comment #20: 

Triangles are buffered one after the other in an octave_polygon object using the `octave_polygon::add` method. At this stage a triangle is merged with the previous one if it can be.

When only consecutive triangles can be merged, as in the original example, all the work has been done before the expensive octave_polygon::mergepoly method is called, so it consumes much times and doesn't do anything useful, as noticed by jwe.

Now with the following 3D example (smaller so that I don't have to wait minutes in front of my old computer), I can see a difference in file size

cla
sombrero (10);
ch = get (gca, "children");
set (ch, "facecolor", "r", "edgecolor", "none")
view (2)
print toto_svgconvert_old.svg
ls -lh toto*

which gives

... 179K Jan 16 22:03 toto_nosvgconvert.svg
... 110K Jan 16 22:02 toto_svgconvert_new.svg
... 47K Jan 16 22:25 toto_svgconvert_old.svg

With the old code, more polygons are merged (not only consecutive ones) but the result is still far from perfect (due mainly to the coordinate comparison tolerance). I attached the svg files so that you can inspect them and see visual artifacts.

(file #54235, file #54236, file #54237)

Pantxo Diribarne <pantxo>
Project Member
Mon 16 Jan 2023 09:14:33 PM UTC, comment #19: 

Re the algorithm description, yes it's theoretically possible that if the polygon at index 0 cannot be merged with anything else then the merging will stop, even if others can be merged with each other, but it seems to not happen in practice, at least for the kind of figures routinely generated with plot(), spy(), etc. In effect, instead of using the full graph between polygons, the new technique collapses only the component of the graph that contains vertex 0, leaving other components as they are. But most of the graphs (sets of polygons) passed to that function have only one big component anyway, so plotting the first component is sufficient in those cases.

I am willing to change the algorithm based on feedback -- are we seeking the merging of all possible polygons, or is a faster technique acceptable at the cost of missing components?

Arun Giridhar <arungiridhar>
Project Member
Mon 16 Jan 2023 07:39:35 PM UTC, comment #18: 

svg difference seems to be superficial:

$ diff blahU.svg blahP.svg | head
2c2
< <svg xmlns="http://www.w3.org/2000/svg" xmlns:xlink="http://www.w3.org/1999/xlink" width="420pt" viewBox="0 0 420 315" height="315pt">
---
> <svg height="315pt" xmlns="http://www.w3.org/2000/svg" viewBox="0 0 420 315" width="420pt" xmlns:xlink="http://www.w3.org/1999/xlink">
12c12
<   <polygon points="0,315 420,315 420,0 0,0" fill="#ffffff" shape-rendering="crispEdges"/>
---
>   <polygon shape-rendering="crispEdges" points="0,315 420,315 420,0 0,0" fill="#ffffff"/>

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Mon 16 Jan 2023 07:05:30 PM UTC, comment #17: 

When I do a diff on the patched EPS and unpatched EPS, only the timestamp is different. The rest of the file is the same.

With SVG:

$ diff blah2_v8_unpatched.eps blah2_v8_patched.eps
7c7
< %%CreationDate: D:20230116135711-05'00'
---
> %%CreationDate: D:20230116135346-05'00'

$ diff blah2_v9_unpatched.eps blah2_v8_patched.eps
7c7
< %%CreationDate: D:20230116135339-05'00'
---
> %%CreationDate: D:20230116135346-05'00'

Without SVG:

$ diff blah_v8_unpatched.eps blah_v8_patched.eps
7c7
< %%CreationDate: Mon Jan 16 13:54:21 2023
---
> %%CreationDate: Mon Jan 16 13:53:43 2023

$ diff blah_v9_unpatched.eps blah_v8_patched.eps
7c7
< %%CreationDate: Mon Jan 16 13:50:49 2023
---
> %%CreationDate: Mon Jan 16 13:53:43 2023

Arun Giridhar <arungiridhar>
Project Member
Mon 16 Jan 2023 06:22:00 PM UTC, comment #16: 

I do not pretend to understand the algorithm, but I did the following test. In octave:

    n = 333;
    a = 10*speye (n) + sparse (1:n,ceil ([1:n]/2),1,n,n) + ...
        sparse (ceil ([1:n]/2),1:n,1,n,n);
    r1 = chol (a);
    spy (r1);
    axis ("ij");
    print -nosvgconvert blah0.svg

In the shell:

$ time ./octave-svgconvert_U blah0.svg svg 100 FreeSans.otf 1 blahU.svg

real        2m55.159s
user        2m54.826s
sys        0m0.108s

$ time ./octave-svgconvert_P blah0.svg svg 100 FreeSans.otf 1 blahP.svg

real        0m1.438s
user        0m1.326s
sys        0m0.104s

ls -gG
total 25968
-rw-r--r--. 1 15617770 Jan 16 12:57 blah0.svg
-rw-------. 1  4984800 Jan 16 13:08 blahP.svg
-rw-------. 1  4984800 Jan 16 13:07 blahU.svg
-rwxr-xr-x. 1   851328 Jan 16 12:55 octave-svgconvert_P
-rwxr-xr-x. 1   148152 Jan 16 13:02 octave-svgconvert_U

"P" -- patched, "U" -- unpatched.
Files blahP.svg and blahU.svg although of the same size are different. Both loads in a viewer noticeably faster than the original blah0.svg.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Mon 16 Jan 2023 04:30:07 PM UTC, comment #15: 

Does the updated algorithm actually merge polygons? I'm struggling to understand what it does.

Let's say there are 5 polygons A,B,C,D,E. Let's say B&D and C&E can be merged.
The new algorithm starts by selecting A. It checks in a loop whether A can be merged to any of the other polygons. Since it can't, the outer "tryagain" loop would stop.
Where does it check whether any of the other polygons can be merged?
Am I missing something obvious?

Markus Mützel <mmuetzel>
Project Member
Mon 16 Jan 2023 04:12:10 PM UTC, comment #14: 

At n=400, I got "GL2PS info: OpenGL feedback buffer overflow warning: gl2ps_renderer::draw: retrying with buffer size: 8.4E+06 B"; I did not want that to skew profiling, so dropped the size to 333. I do not see any other errors/warnings.

For the reference, the timings (for n=400) are: original -- 360 sec, patched -- 2.85 sec.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Mon 16 Jan 2023 02:36:16 PM UTC, comment #13: 

When I tried with n = 333, the patched version still works as required. The unpatched versions for both default and stable give an error "ICE default IO error handler doing an exit(), pid = ....., errno = 32". The files blah.eps and blah2.eps are written correctly though.

Not sure what the error means or where it comes from. A grep and a web search didn't give anything useful. But the patched version doesn't seem to have it, so maybe it's coming from Qt.

octave:1> clear all; close all; tic; n = 333; a = 10*speye(n) + sparse(1:n, ceil([1:n]/2),1,n,n) + sparse(ceil([1:n]/2),1:n,1,n,n); r1 = chol(a); spy(r1,'.',10); axis ij; toc, tic; print -nosvgconvert -depsc2 blah.eps; toc, tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 0.15465 seconds.
Elapsed time is 0.621703 seconds.
ICE default IO error handler doing an exit(), pid = 64828, errno = 32
Elapsed time is 170.381 seconds.
octave:2> exit


octave:1> clear all; close all; tic; n = 333; a = 10*speye(n) + sparse(1:n, ceil([1:n]/2),1,n,n) + sparse(ceil([1:n]/2),1:n,1,n,n); r1 = chol(a); spy(r1,'.',10); axis ij; toc, tic; print -nosvgconvert -depsc2 blah.eps; toc, tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 0.163769 seconds.
Elapsed time is 0.602484 seconds.
ICE default IO error handler doing an exit(), pid = 88991, errno = 32
Elapsed time is 167.311 seconds.
octave:2> exit

Arun Giridhar <arungiridhar>
Project Member
Sun 15 Jan 2023 10:58:49 PM UTC, comment #12: 

Attaching an updated patch with a commit message etc. In addition to the changes from comment #10, I used an initializer to eliminate the first loop, and reduced the indent level in a few places by using `continue`, and added a commit message.

Since this is going to stable, I didn't push it directly. More review can't hurt. Patch attached.

(file #54233)

Arun Giridhar <arungiridhar>
Project Member
Sun 15 Jan 2023 08:24:21 PM UTC, comment #11: 

I confirm a ~25x speedup. Attached the profiler report for
a slightly modified test case (increased n to 333 and save to
svg to remove ghostscript from the problem):

    n = 333;
    a = 10*speye (n) + sparse (1:n,ceil ([1:n]/2),1,n,n) + ...
        sparse (ceil ([1:n]/2),1:n,1,n,n);
    r1 = chol (a);
    spy (r1);
    axis ("ij");
    tic; print -svgconvert blah2.svg; toc

Elapsed time is 1.86183 seconds.

I do not see an obvious bottleneck here.

Dmitri.
--


Dmitri A. Sergatskov <dasergatskov>
Sun 15 Jan 2023 06:16:50 PM UTC, comment #10: 

I'm attaching a patch "svg.patch" that improves the performance some 25x overall. Also two intermediate patches "time_old.patch" and "time_new.patch" with time measurement code for reproducibility.

Baseline, unpatched 3678187f4355:

octave:1> clear all; tic; n = 200; a = 10*speye(n) + sparse(1:n, ceil([1:n]/2),1,n,n) + sparse(ceil([1:n]/2),1:n,1,n,n); r1 = chol(a); spy(r1); axis ij; toc, tic; print -nosvgconvert -depsc2 blah.eps; toc, tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 0.173405 seconds.
Elapsed time is 0.33665 seconds.
Elapsed time is 24.8665 seconds.

With instrumentation for time measurement but no change in functionality:

octave:1> clear all; tic; n = 200; a = 10*speye(n) + sparse(1:n, ceil([1:n]/2),1,n,n) + sparse(ceil([1:n]/2),1:n,1,n,n); r1 = chol(a); spy(r1); axis ij; toc, tic; print -nosvgconvert -depsc2 blah.eps; toc, tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 0.164773 seconds.
Elapsed time is 0.35028 seconds.
setup time                      0μs
merge time                      0μs
crack time                      0μs
final time                      3μs

setup time                      0μs
merge time                      0μs
crack time                      0μs
final time                      0μs

setup time                      0μs
merge time                      0μs
crack time                      0μs
final time                      0μs

setup time                     30μs
merge time               22873717μs
crack time                    787μs
final time                    388μs

Elapsed time is 23.851 seconds.

Observation: unused[0] always stays false, because jj can never be 0 in unused[jj] = true, since jj >= ii+1.

The outer for-loop on ii can therefore be eliminated, setting it to zero.

With instrumentation and that patch:

octave:1> clear all; tic; n = 200; a = 10*speye(n) + sparse(1:n, ceil([1:n]/2),1,n,n) + sparse(ceil([1:n]/2),1:n,1,n,n); r1 = chol(a); spy(r1); axis ij; toc, tic; print -nosvgconvert -depsc2 blah.eps; toc, tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 0.145507 seconds.
Elapsed time is 0.336081 seconds.
setup time                      0μs
merge time                      0μs
crack time                      0μs
final time                      0μs

setup time                      0μs
merge time                      0μs
crack time                      0μs
final time                      0μs

setup time                      0μs
merge time                      0μs
crack time                      0μs
final time                      0μs

setup time                     34μs
merge time                   4861μs
crack time                    684μs
final time                    363μs

Elapsed time is 0.935894 seconds.

That nested loop becomes 22873717 / 4861 == some 4700 times faster in this case. There may be pathological cases but hopefully those are rare.

Removing the time measurement code to give the patched performance:

octave:1> clear all; tic; n = 200; a = 10*speye(n) + sparse(1:n, ceil([1:n]/2),1,n,n) + sparse(ceil([1:n]/2),1:n,1,n,n); r1 = chol(a); spy(r1); axis ij; toc, tic; print -nosvgconvert -depsc2 blah.eps; toc, tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 0.171607 seconds.
Elapsed time is 0.33852 seconds.
Elapsed time is 0.931587 seconds.

It would still be nice to make the svgconvert speed the same as nosvgconvert speed but this removes one bottleneck at least.

(file #54229, file #54230, file #54231)

Arun Giridhar <arungiridhar>
Project Member
Sun 15 Jan 2023 01:30:23 PM UTC, comment #9: 

@jwe:

>> ... the result for this example is that no merges ever happen


At least for me the SVG file size is reduced from 5.7 MB with -nosvconvert to 1.8 MB with svgconvert. This is the result of merging 3 triangles forming the original dot (hexagon) marker to a single hexagon path.

>> Is there a better way to do this job other than by an exhaustive search?


I don't know. This is the most basic approach I came to but there may be much more efficient ones.

>> How important is it to merge the polygons?


For small makers the difference is hardly visible in SVG and PDF printouts but for large polygons then you'll notice that unless the triangles are merged into polygons viewers let white (background color) lines appear between triangles.

>> Could we make it optional?


octave-svgconvert has an option to enable/disable that merging step, which is enabled by default. We could expose that option through a print option.

Pantxo Diribarne <pantxo>
Project Member
Sat 14 Jan 2023 03:16:32 AM UTC, comment #8: 

For the example in this report, the nested loops in the following code in octave_polygon::reconstruct end up calling mergepoly around 52 million times (if I understand, correctly, it would be (10200^2-10200)/2 == 52014900 calls).  That appears to be what takes all the time and the result for this example is that no merges ever happen.  I guess that's good though, because if any merge is detected, the whole loop will be executed again, and in the worst case, as few as one polygon might have been added to the unused list.  Is there a better way to do this job other than by an exhaustive search?  How important is it to merge the polygons?  Could we make it optional?

    bool tryagain = (m_polygons.count () > 1);

    while (tryagain)
      {
        tryagain = false;
        for (auto ii = 0; ii < m_polygons.count (); ii++)
          {
            if (! unused[ii])
              {
                QPolygonF polygon = m_polygons[ii];
                for (auto jj = ii+1; jj < m_polygons.count (); jj++)
                  {
                    if (! unused[jj])
                      {
                        QPolygonF newpoly = mergepoly (polygon, m_polygons[jj]);
                        if (newpoly.count ())
                          {
                            polygon = newpoly;
                            m_polygons[ii] = newpoly;
                            unused[jj] = true;
                            tryagain = true;
                          }
                      }
                  }
              }
          }
      }

John W. Eaton <jwe>
Project Administrator
Fri 13 Jan 2023 10:05:05 PM UTC, comment #7: 

I also noticed that cpu load stays very low (~3%), so I assume
most of the time is spent in memory access (?!).

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Fri 13 Jan 2023 09:44:50 PM UTC, comment #6: 

>> I think the proximate reason for the slow behavior is the switch of the default during printing to include "-svgconvert" option.


Yes the issue seems to be, like Dmitri said, that octave-svgconvert reconstructs all the 10200 dot markers (actually hexagons made of 3 triangles)...

I'd still vote for keeping the -svgconvert option as the default. We could use the -nosvgconvert switch for this particular figure as proposed by Rik and add a warning in the doc about the slow execution time when there are many markers in the figure.

Pantxo Diribarne <pantxo>
Project Member
Fri 13 Jan 2023 05:00:52 PM UTC, comment #5: 

Just for completeness, I'm attaching the code to generate the figure in question as mk_spchol.m.

Using the development branch of octave and run-gui -f (so that none of my personal settings interfere with timing)

octave:1> tic; mk_spchol; toc
Elapsed time is 0.754476 seconds.
octave:2> graphics_toolkit
ans = qt
octave:3> tic; print -depsc2 -nosvgconvert tmp1.eps; toc
Elapsed time is 0.615009 seconds.
octave:4> tic; print -depsc2 tmp2.eps; toc
Elapsed time is 48.3406 seconds.

I think the proximate reason for the slow behavior is the switch of the default during printing to include "-svgconvert" option.  In Mercurial logs,

changeset:   31432:df8bdaf1164b
user:        Pantxo Diribarne <pantxo.diribarne@gmail.com>
date:        Mon Aug 29 18:29:24 2022 +0200
summary:     print.m: Use -svgconvert by default (bug #62979)

The Mercurial tag for Octave version 7.3 is changeset 31390 so printing in 7.3 should not be affected.  At least for me, this is the case with my testing.

Incidentally, I also see the same thing with printing to svg.  This might indicate that we are incorrectly using the svgconvert change even on file types that don't need it.

octave:3> tic; print -nosvgconvert -dsvg blah2.svg; toc
Elapsed time is 0.290739 seconds.
octave:4> tic; print -dsvg blah2.svg; toc
Elapsed time is 44.2066 seconds.

(file #54220)

Rik <rik5>
Project Administrator
Fri 13 Jan 2023 02:13:32 PM UTC, comment #4: 

Attached is the result of running AMD uProf
( https://developer.amd.com/amd-uprof/) on

tic; print -svgconvert -depsc2 blah2.eps; toc

This is on Centos 9 Stream / ryzen 3950.

Also, after saving the pic into "blah.svg":

$ time /usr/local/libexec/octave/8.0.1/exec/x86_64-pc-linux-gnu/octave-svgconvert blah.svg svg 100 FreeSans.otf 1 blahX.svg

real        0m19.981s
user        0m19.932s
sys        0m0.023s

$ time /usr/local/libexec/octave/8.0.1/exec/x86_64-pc-linux-gnu/octave-svgconvert blah.svg svg 100 FreeSans.otf 0 blahX.svg

real        0m0.193s
user        0m0.171s
sys        0m0.019s

Dmitri.
--


Dmitri A. Sergatskov <dasergatskov>
Fri 13 Jan 2023 01:46:48 PM UTC, comment #3: 

Did we change "octave-svgconvert" option "reconstruct" from 0 to 1
recently? That might explain the slowdown.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Fri 13 Jan 2023 10:56:00 AM UTC, comment #2: 

I don't get quite the same numbers on my system (old laptop with ubuntu 20.04) and Octave 7.3:

octave:6> tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 455.944 seconds.
octave:7> tic; print -depsc2 blah2.eps; toc
Elapsed time is 328.811 seconds.

So for me the bottleneck seems to be gl2ps rather than svgconvert (which is just 35% slower).

 

I'll try with another computer where I have both Octave 7.3 and Octave 8.01 and see if I can confirm.

Pantxo Diribarne <pantxo>
Project Member
Fri 13 Jan 2023 10:30:59 AM UTC, comment #1: 

Is this only an issue with the graphics for the manual? Or should the default for printing to eps be reset to `-nosvgconvert`?
What would that imply?

Markus Mützel <mmuetzel>
Project Member
Fri 13 Jan 2023 05:39:47 AM UTC, original submission:  

Creation time for "spchol" image in the Octave manual has become very long.

The code to generate the image runs quite quickly (0.3 seconds on my PC).

    n = 200;
    a = 10*speye (n) + sparse (1:n,ceil ([1:n]/2),1,n,n) + ...
        sparse (ceil ([1:n]/2),1:n,1,n,n);
    r1 = chol (a);
    spy (r1);
    axis ("ij");

However, the print command is quite slow

octave:9> tic; print -nosvgconvert -depsc2 blah.eps; toc
Elapsed time is 1.0838 seconds.
octave:10> tic; print -svgconvert -depsc2 blah2.eps; toc
Elapsed time is 54.0847 seconds.

If there is no obvious way to improve efficiency of the -svgconvert option then I think it should be disabled for generation of this particular figure.  This would not be hard as there is already a special test for eps output which sets an option to the print command.

Rik <rik5>
Project Administrator

 

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

Attach Files:
   
   
Comment:
   

Attached Files
file #54235:  toto_nosvgconvert.svg added by pantxo (178KiB - image/svg+xml)
file #54236:  toto_svgconvert_new.svg added by pantxo (109KiB - image/svg+xml)
file #54237:  toto_svgconvert_old.svg added by pantxo (47KiB - image/svg+xml)
file #54233:  svg_full.patch added by arungiridhar (3KiB - text/x-patch)
file #54229:  svg.patch added by arungiridhar (2KiB - text/x-patch)
file #54230:  time_old.patch added by arungiridhar (2KiB - text/x-patch)
file #54231:  time_new.patch added by arungiridhar (3KiB - text/x-patch)
file #54220:  mk_spchol.m added by rik5 (145B - text/x-matlab)
file #54218:  uprofile1.png added by dasergatskov (135KiB - image/png)

 

Depends on the following items: None found

Items that depend on this one: None found

 

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

    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 project members can vote.

     

     

     

     

    Follow 20 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2023-02-01 mmuetzel Fixed ReleaseNone 8.1.0 (current stable)
    2023-01-31 pantxo StatusReady For Test Fixed
        Open/ClosedOpen Closed
    2023-01-31 mmuetzel StatusPatch Reviewed Ready For Test
        Planned ReleaseNone 8.1.0 (current stable)
    2023-01-30 pantxo StatusPatch Submitted Patch Reviewed
    2023-01-30 mmuetzel Attached File- Added bug63646-print-svgconvert-polymerge-v2.patch, #54289
    2023-01-29 mmuetzel Attached File- Added bug63646-print-svgconvert-polymerge.patch, #54283
    2023-01-16 pantxo Attached File- Added toto_nosvgconvert.svg, #54235
        Attached File- Added toto_svgconvert_new.svg, #54236
        Attached File- Added toto_svgconvert_old.svg, #54237
    2023-01-15 arungiridhar Attached File- Added svg_full.patch, #54233
    2023-01-15 dasergatskov Attached File- Added uprofile_svgpatch.png, #54232
    2023-01-15 arungiridhar Attached File- Added svg.patch, #54229
        Attached File- Added time_old.patch, #54230
        Attached File- Added time_new.patch, #54231
        StatusConfirmed Patch Submitted
    2023-01-13 rik5 Attached File- Added mk_spchol.m, #54220
    2023-01-13 dasergatskov Attached File- Added uprofile1.png, #54218
    2023-01-13 rik5 Carbon-Copy- Added pantxo

    Back to the top

    Powered by Savane 3.10