bugGNU Octave - Bugs: bug #61259, slow printing of images

 
 

bug #61259: slow printing of images

Submitter:  Fabio <efferre79>
Submitted:  Thu 30 Sep 2021 10:17:17 PM UTC
   
 
Category:  Plotting Severity:  3 - Normal
Priority:  5 - Normal Item Group:  Performance
Status:  Need Info Assigned to:  None
Originator Name:  Open/Closed:  * Open
Release:  * 6.2.0 Operating System:  * GNU/Linux
Fixed Release:  None Planned Release:  None
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Tue 05 Oct 2021 09:09:56 PM UTC, comment #9: 

If you run top in a separate windows you would notice that most of the time is being is being used by ghostscript (that converts postscript into either png or pdf). With qt backend you can eliminate most of it if you add "-svgconvert" parameter to print.
With those mods I got the following results on my 13+ years old laptop (Intel Core2 Duo CPU     T9900  @ 3.06GHz), octave 6.3.0
on Fedora 35:



octave:1> t_print
agt =
{
  [1,1] = qt
}


number of points is 100000

toolkit is qt
figure visibility is on
printing of png took 0.490375 seconds
printing of pdf took 3.254296 seconds
figure visibility is off
printing of png took 0.355418 seconds
printing of pdf took 3.050011 seconds

number of points is 1000000

toolkit is qt
figure visibility is on
printing of png took 0.579070 seconds
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 8.4E+06 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 1.7E+07 B
printing of pdf took 15.954510 seconds
figure visibility is off
printing of png took 0.472160 seconds
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 8.4E+06 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 1.7E+07 B
printing of pdf took 15.998050 seconds

number of points is 10000000

toolkit is qt
figure visibility is on
printing of png took 3.074761 seconds
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 8.4E+06 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 1.7E+07 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 3.4E+07 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 6.7E+07 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 1.3E+08 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 2.7E+08 B
printing of pdf took 93.645220 seconds
figure visibility is off
printing of png took 1.648946 seconds
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 8.4E+06 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 1.7E+07 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 3.4E+07 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 6.7E+07 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 1.3E+08 B
GL2PS info: OpenGL feedback buffer overflow
GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: 2.7E+08 B
printing of pdf took 91.062127 seconds
octave:2>


Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 05 Oct 2021 05:30:54 PM UTC, comment #8: 

I confirm the same result with octave 6.3.0, I don't know how to change the metadata of this bug

Fabio <efferre79>
Tue 05 Oct 2021 05:29:48 PM UTC, comment #7: 

the updated test script is


agt=available_graphics_toolkits;
v={'on','off'};

for n=[1e5 1e6 10e6]
        fprintf(1,'\nnumber of points is %d\n\n', n)
        x=linspace(1,2,n);

        for k=1:length(agt)
                close all
                graphics_toolkit(agt{k});
                fprintf(1,'toolkit is %s\n', agt{k})

                for j=1:length(v)
                        if strcmp(agt{k},'fltk') && strcmp(v{j}, 'off')
                                fprintf(1, 'skipping test for %s where visibility is off\n', agt{k})
                                continue
                        end

                        fprintf(1,'figure visibility is %s\n', v{j})

                        figure(1,'visible', v{j})
                        subplot(2,1,1)
                        plot(x,x)
                        subplot(2,1,2)
                        plot(x,-x)
                        tic;print('test_large.png');et=toc;
                        %tic;saveas(gcf,'test_large.png');et=toc;
                        fprintf(1,'printing of png took %f seconds\n', et)
                        %fprintf(1,'saveas of png took %f seconds\n', et)
                        tic;print('test_large.pdf');et=toc;
                        %tic;saveas(gcf,'test_large.pdf');et=toc;
                        fprintf(1,'printing of pdf took %f seconds\n', et)
                        %fprintf(1,'saveas of pdf took %f seconds\n', et)
                end
        end
end


Fabio <efferre79>
Tue 05 Oct 2021 05:27:08 PM UTC, comment #6: 

I am running the tests on a i7-6700 CPU with 32GB of RAM, it has an embedded Intel integrated graphics. There are two swap partitions of 8GB. The application is not swapping during its execution.

Regarding the opengl buffer overflow, as described in #49482, the default starting value is very small (2 MB) considering today's memory sizes and this causes many iterations before finding the right value. Besides decimating the data, another option might be to suggest the initial value for the buffer size (of course this needs changing the code of octave a little bit) to avoid many iterations.

Thanks for pointing out the issue regarding the change of toolkit vs open figures. I have modified the script and executed again it with software and hardware rendering. The numbers are odd, why I get better results with software rendering? Moreover, with software rendering the results are independent of figure visibility while in the other case the numbers differ.

Here are the numbers:

* with hardware rendering *

OpenGL vendor string: Intel Open Source Technology Center
OpenGL renderer string: Mesa DRI Intel(R) HD Graphics 530 (SKL GT2)
OpenGL core profile version string: 4.6 (Core Profile) Mesa 21.1.7
OpenGL core profile shading language version string: 4.60
OpenGL version string: 3.0 Mesa 21.1.7
OpenGL shading language version string: 1.30
OpenGL ES profile version string: OpenGL ES 3.2 Mesa 21.1.7
OpenGL ES profile shading language version string: OpenGL ES GLSL ES 3.20

number of points is 100000

toolkit is fltk
figure visibility is on
printing of png took 3.304928 seconds
printing of pdf took 2.808755 seconds
skipping test for fltk where visibility is off
toolkit is gnuplot
figure visibility is on
printing of png took 1.411992 seconds
printing of pdf took 1.337175 seconds
figure visibility is off
printing of png took 0.784361 seconds
printing of pdf took 0.865343 seconds
toolkit is qt
figure visibility is on
printing of png took 4.799125 seconds
printing of pdf took 4.927203 seconds
figure visibility is off
printing of png took 2.328467 seconds
printing of pdf took 2.567297 seconds

number of points is 1000000

toolkit is fltk
figure visibility is on
printing of png took 30.306956 seconds
printing of pdf took 31.902370 seconds
skipping test for fltk where visibility is off
toolkit is gnuplot
figure visibility is on
printing of png took 12.315117 seconds
printing of pdf took 11.951613 seconds
figure visibility is off
printing of png took 6.122746 seconds
printing of pdf took 6.100312 seconds
toolkit is qt
figure visibility is on
printing of png took 93.662863 seconds
printing of pdf took 94.320593 seconds
figure visibility is off
printing of png took 22.948703 seconds
printing of pdf took 25.533747 seconds

number of points is 10000000

toolkit is fltk
figure visibility is on
printing of png took 529.557504 seconds
printing of pdf took 549.620309 seconds
skipping test for fltk where visibility is off
toolkit is gnuplot
figure visibility is on
printing of png took 129.594642 seconds
printing of pdf took 130.050794 seconds
figure visibility is off
printing of png took 63.390391 seconds
printing of pdf took 61.720492 seconds
toolkit is qt
figure visibility is on
printing of png took 1964.156863 seconds
printing of pdf took 1987.328518 seconds
figure visibility is off
printing of png took 337.246404 seconds
printing of pdf took 363.229381 seconds




* with software rendering *

OpenGL vendor string: Mesa/X.org
OpenGL renderer string: llvmpipe (LLVM 12.0.1, 256 bits)
OpenGL core profile version string: 4.5 (Core Profile) Mesa 21.1.7
OpenGL core profile shading language version string: 4.50
OpenGL version string: 3.1 Mesa 21.1.7
OpenGL shading language version string: 1.40
OpenGL ES profile version string: OpenGL ES 3.2 Mesa 21.1.7
OpenGL ES profile shading language version string: OpenGL ES GLSL ES 3.20

number of points is 100000

toolkit is fltk
figure visibility is on
printing of png took 3.099921 seconds
printing of pdf took 2.463096 seconds
skipping test for fltk where visibility is off
toolkit is gnuplot
figure visibility is on
printing of png took 1.427321 seconds
printing of pdf took 1.450138 seconds
figure visibility is off
printing of png took 0.788535 seconds
printing of pdf took 0.789970 seconds
toolkit is qt
figure visibility is on
printing of png took 2.445887 seconds
printing of pdf took 2.493091 seconds
figure visibility is off
printing of png took 2.257260 seconds
printing of pdf took 2.484798 seconds

number of points is 1000000

toolkit is fltk
figure visibility is on
printing of png took 20.979849 seconds
printing of pdf took 21.887293 seconds
skipping test for fltk where visibility is off
toolkit is gnuplot
figure visibility is on
printing of png took 12.101142 seconds
printing of pdf took 11.926311 seconds
figure visibility is off
printing of png took 6.074225 seconds
printing of pdf took 6.330998 seconds
toolkit is qt
figure visibility is on
printing of png took 21.796262 seconds
printing of pdf took 22.823234 seconds
figure visibility is off
printing of png took 20.309321 seconds
printing of pdf took 21.275576 seconds

number of points is 10000000

toolkit is fltk
figure visibility is on
printing of png took 273.660133 seconds
printing of pdf took 272.683319 seconds
skipping test for fltk where visibility is off
toolkit is gnuplot
figure visibility is on
printing of png took 120.774204 seconds
printing of pdf took 124.490717 seconds
figure visibility is off
printing of png took 63.017600 seconds
printing of pdf took 62.645626 seconds
toolkit is qt
figure visibility is on
printing of png took 368.520071 seconds
printing of pdf took 365.772126 seconds
figure visibility is off
printing of png took 322.749520 seconds
printing of pdf took 342.344563 seconds


Fabio <efferre79>
Fri 01 Oct 2021 05:07:53 PM UTC, comment #5: 

@Dasergatskov: is that equivalent to "export  LIBGL_ALWAYS_SOFTWARE=1" in .bashrc and then starting Octave manually?

Anonymous
Fri 01 Oct 2021 12:40:44 PM UTC, comment #4: 

To switch graphics toolkit you need either close all figures or open a new one. So all youe test times done with fltk.
But in any case something is definitely wrong with your computer.
On my computer(s) it happens about 10 to 20 times faster.
If you are using mesa OpenGL (rather than a proprietary one, e.g. Nvidia) you can try to start octave as


LIBGL_ALWAYS_SOFTWARE=1 octave


On my laptop (with an integrated intel graphics) it is ~10% faster.

Dmitri.
--



Dmitri A. Sergatskov <dasergatskov>
Fri 01 Oct 2021 12:23:11 PM UTC, comment #3: 

When a figure has been created by a given graphics toolkit you must specify its handle to the "graphics_toolkit" function in order to have it redrawn by the requested tookit, i.e., in your example, you should have "graphics_toolkit (1, agt{k});"

This should change your numbers, i.e. :

  • gnuplot should have very different timings than other tookits,
  • for "qt" toolkit raster images (png here) will be much faster for large point numbers.


Does it?

Now for vector formats (pdf here) with qt/fltk toolkits, Octave doesn't do any filtering to data before printing and gl2ps (which is behind the `painters` printing renderer) thus has to retrieve/parse/sort/print as may point coordinates as the axes object contains. The timings should be proportional to the point number, until you reach the default data buffer size... As you noted, with large point numbers you'll exceed the default size and Octave will try again with a buffer twice as large, which may not be enough...

So finally, if you can live with raster images, and "qt" toolkit (the default) fits your needs you should choose this solution.
Otherwise, you'll have to decimate data before printing.

Pantxo Diribarne <pantxo>
Group Member
Fri 01 Oct 2021 03:25:08 AM UTC, comment #2: 

To the OP: can you share your system configuration? How much memory do you have and is swap space being used by any of the image save calls?

Anonymous
Thu 30 Sep 2021 10:55:42 PM UTC, comment #1: 

Out of curiosity, is there any performance difference between print and saveas?

The gl2ps thing is certainly odd but it doesn't explain why converting to raster formats is slow as well. It also doesn't explain the superlinear scaling as the number of points increases.

Anonymous
Thu 30 Sep 2021 10:17:17 PM UTC, original submission:  

I am facing a performance issue when trying to export an image if the data size is huge. The result is quite different when the figure is visible or not. The exec time is independent of bitmap/vector output format.

I am using the qt toolkit but I have tried all toolkits with more or less the same result. I have written the following test:


agt=available_graphics_toolkits;
x=linspace(1,2,1e6);
v={'on','off'};

for j=1:length(v)
    fprintf(1,'figure visibility is %s\n', v{j})
    figure(1,'visible', v{j})

    for k=1:length(agt)
        graphics_toolkit(agt{k});
        fprintf(1,'toolkit is %s\n', agt{k})

        clf
        plot(x,x)
        tic;print('test_large.png');et=toc;
        fprintf(1,'printing of png took %f seconds\n', et)
        tic;print('test_large.pdf');et=toc;
        fprintf(1,'printing of pdf took %f seconds\n', et)
    end
end


with 1e5 points:

figure visibility is on
toolkit is fltk
printing of png took 2.512742 seconds
printing of pdf took 2.580937 seconds
toolkit is gnuplot
printing of png took 2.556829 seconds
printing of pdf took 2.565509 seconds
toolkit is qt
printing of png took 2.447250 seconds
printing of pdf took 2.536983 seconds
figure visibility is off
toolkit is fltk
printing of png took 1.164396 seconds
printing of pdf took 1.251188 seconds
toolkit is gnuplot
printing of png took 1.195915 seconds
printing of pdf took 1.297156 seconds
toolkit is qt
printing of png took 1.207151 seconds
printing of pdf took 1.240340 seconds

with 1e6 points:

figure visibility is on
toolkit is fltk
printing of png took 43.931664 seconds
printing of pdf took 44.527668 seconds
toolkit is gnuplot
printing of png took 44.168895 seconds
printing of pdf took 44.763425 seconds
toolkit is qt
printing of png took 43.786862 seconds
printing of pdf took 45.107477 seconds
figure visibility is off
toolkit is fltk
printing of png took 11.101900 seconds
printing of pdf took 11.941227 seconds
toolkit is gnuplot
printing of png took 11.286645 seconds
printing of pdf took 11.907872 seconds
toolkit is qt
printing of png took 11.394462 seconds
printing of pdf took 11.821886 seconds

with 10e6 points:

figure visibility is on
toolkit is fltk
printing of png took 989.613597 seconds
printing of pdf took 1037.992974 seconds
toolkit is gnuplot
printing of png took 978.964138 seconds
printing of pdf took 940.796408 seconds
toolkit is qt
printing of png took 950.266446 seconds
printing of pdf took 1281.552140 seconds

figure visibility is off
toolkit is fltk
printing of png took 171.231403 seconds
printing of pdf took 183.784420 seconds
toolkit is gnuplot
printing of png took 171.192138 seconds
printing of pdf took 182.603688 seconds
toolkit is qt
printing of png took 208.856389 seconds
printing of pdf took 264.242813 seconds

Here for 1e6 and 10e6 points I have filtered out from the output the following warnings:

GL2PS info: OpenGL feedback buffer overflow
warning: gl2ps_renderer::draw: retrying with buffer size: xxx B

where the buffer size is progressively increased (even many times for each print() call) with the effect of taking more and more time for the execution

Fabio <efferre79>

 

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

Attach Files:
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by dasergatskov (Posted a comment)
  • -email is unavailable- added by pantxo (Posted a comment)
  • -email is unavailable- added by efferre79 (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.

     

    Follows 1 latest change.

    Date Changed by Updated Field Previous Value => Replaced by
    2021-10-01 pantxo StatusNone Need Info

    Back to the top

    Powered by Savane 3.13-758e.
    Corresponding source code