bugGNU Octave - Bugs: bug #66012, printing to the pdflatex device is...

 
 

bug #66012: printing to the pdflatex device is slow

Submitter:  Robert Jenssen <morgawr>
Submitted:  Mon 22 Jul 2024 11:36:32 AM UTC
   
 
Category:  Plotting with OpenGL Severity:  3 - Normal
Priority:  5 - Normal Item Group:  Regression
Status:  Confirmed Assigned to:  None
Originator Name:  Open/Closed:  * Open
Release:  * 9.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

Thu 25 Jul 2024 11:03:39 PM UTC, comment #14: 

Here is an example of finding a text extent in latex:

\documentclass{minimal}
\usepackage{calc}
\begin{document}
 \newlength{\tml}
 \settowidth{\tml}{$10^{-2}$}
 \the\tml \\
 $10^{-2}$
\end{document}


Save this as x.tex, then compile and view this with:

$ latex x.tex && dvips x.dvi && evince x.ps


"\tml" is a variable that you can use elsewhere in the latex program.

Robert Jenssen <morgawr>
Thu 25 Jul 2024 09:56:26 PM UTC, comment #13: 

On my system I see the timings for the three operations
are

tic; for ii = 1:10, system ('latex tst.tex'); end; toc   ## -> 0.140 s/call
tic; for ii = 1:20, system ('dvipng tst.dvi'); end; toc  ## -> 0.135 s/call
tic; for ii = 1:20, system ('dvisvgm tst.dvi'); end; toc ## -> 0.235 s/call

So 45 % of the time is spent preparing an svg image that will only be useful if the user finally prints with the svgconvert tool. So, for an improvement of a factor of almost 2, instead of storing the content of the svg file in the cache, as we currently do, we may want to store the content of the dvi (binary) file and let the gl2ps_renderer run dvisvgm only when needed.

Pantxo Diribarne <pantxo>
Group Member
Thu 25 Jul 2024 03:42:49 PM UTC, comment #12: 

@Pantxo: I think your question is the correct one.  This isn't an issue about working or not working, it is an engineering tradeoff about whether the reward (shorter print execution times) are worth the pain of coding some special cases.  I don't know the code well enough to make that decision.

I would note that rendering the Z-ticks for 2-D scenes really feels like a waste of effort.  There are 3 axes (X, Y, Z) and for a 2-D scene the Z-axis is irrelevant which means 1/3rd of the processing time is unnecessary.  As an example,


plot (1:10)
tic; print ('-dpdflatex', 'tst1'); toc
zticks (linspace (-1, 1, 25));
tic; print ('-dpdflatex', 'tst2'); toc
Elapsed time is 4.21351 seconds.
Elapsed time is 8.65439 seconds.


It feels like that could be clipped by checking is2D boolean.

Rik <rik5>
Group administrator
Thu 25 Jul 2024 09:11:06 AM UTC, comment #11: 

@morgawr: I agree that in this particular situation, we don't actually need to draw the pixels and svg output, so ideally dvipng and dvisvg should not be called (not even latex if I understand comment #8 correctly). Now the question is whether introducing special cases to handle situation where we only want the text extent (like here) or the pixels as well (onscreen rendering and eventually raster print output) or all of them (print vector formats using svgconvert) is worth the effort.

Pantxo Diribarne <pantxo>
Group Member
Thu 25 Jul 2024 08:47:51 AM UTC, comment #10: 

I had forgotten that enabling debug mode for latex not only printed more verbose error messages (as stated in the doc) but also printed cached strings. I definitely don't see 41 calls to latex (and others) but 27:


octave:1> doc "latex"
octave:2> setenv OCTAVE_LATEX_DEBUG_FLAG 1
octave:3>
octave:3> x=rand(1000,1);
octave:4> plot(x);
octave:5> cd /tmp
octave:6> print("x","-dpdflatex");
* Caching ?:10.000000:0:0:0:0
* Caching 0:10.000000:0:0:0:0
* Caching 200:10.000000:0:0:0:0
* Caching 400:10.000000:0:0:0:0
* Caching 600:10.000000:0:0:0:0
* Caching 800:10.000000:0:0:0:0
* Caching 1000:10.000000:0:0:0:0
* Caching 0.2:10.000000:0:0:0:0
* Caching 0.4:10.000000:0:0:0:0
* Caching 0.6:10.000000:0:0:0:0
* Caching 0.8:10.000000:0:0:0:0
* Caching 1:10.000000:0:0:0:0
* Caching -1:10.000000:0:0:0:0
* Caching -0.5:10.000000:0:0:0:0
* Caching 0.5:10.000000:0:0:0:0
* Caching 0:10.000000:1:38:38:38
* Caching 200:10.000000:1:38:38:38
* Caching 400:10.000000:1:38:38:38
* Caching 600:10.000000:1:38:38:38
* Caching 800:10.000000:1:38:38:38
* Caching 1000:10.000000:1:38:38:38
* Caching 0:10.000000:2:38:38:38
* Caching 0.2:10.000000:2:38:38:38
* Caching 0.4:10.000000:2:38:38:38
* Caching 0.6:10.000000:2:38:38:38
* Caching 0.8:10.000000:2:38:38:38
* Caching 1:10.000000:2:38:38:38
octave:7> get (gca, "ztick")
ans =

  -1.0000  -0.5000        0   0.5000   1.0000

octave:8> print("x","-dpdflatex");
octave:9>


The caching key is string:fontsize:horizontalalignment:R:G:B

The latex renderer first tests the latex toolchain by rendering a ? (the character that will be used later when/if some string can't be parsed), then it renders all 11 actually visible ticks [0 200 400 600 800 1000 0.2 0.4 0.6 0.8 1] in black (0:0:0 at the end of the key), but also invisible z tick labels [-1 -0.5 0.5], and finally it re-renders visible tick labels in dark gray (38:38:38).


The last stage is explained by this comment in print .m:


    ## With the -painters (gl2ps) renderer, line transparency is only
    ## handled for svg and pdf outputs using svgconvert.
    ## Otherwise, switch grid lines color to light gray so that the image
    ## output approximately matches on-screen experience.


Pantxo Diribarne <pantxo>
Group Member
Thu 25 Jul 2024 07:13:40 AM UTC, comment #9: 

@Rik: Your example doesn't have any text label or tick, and latex should thus not be called here (the print function only switches axes "ticklabelinterpreter", not text objects "interpreter" contrary to what I said in comment #6). So this is definitely pointing to something different.

Pantxo Diribarne <pantxo>
Group Member
Wed 24 Jul 2024 09:55:59 PM UTC, comment #8: 

The latex "calc" package is required to be part of a LaTeX distribution. It will tell you the extent of strings: width, height and depth (below baseline). I haven't tried to do this myself but I suspect that this is what you want to do. Then you don't need to call latex to render to a bitmap and measure that. I will have a go at writing a simple test case.

Robert Jenssen <morgawr>
Wed 24 Jul 2024 09:16:40 PM UTC, comment #7: 

I'm trying to get this down to a minimum working example.  The following code is attached as prof_latex.m.


close all

hax = gca;
xticklabels ("");
yticklabels ("");
ht = text (0.5, 0.5, 'Hello World', 'fontsize', 20, 'fontname', 'Arial');

profile on
tic;

print -dpdflatex tst_latex

toc
profile off
profshow (10)


profile on
tic;

print -dpdflatex tst_latex2

toc
profile off
profshow (10)


This creates a plot with only one text object.  The results of the profiler are very different between the first run and the second run showing that different code is being executed.


octave:1> prof_latex
Elapsed time is 1.15985 seconds.
   #                  Function Attr     Time (s)   Time (%)        Calls
------------------------------------------------------------------------
  54                       set             1.054      91.45           42
 116                   drawnow             0.032       2.73            3
  36                       get             0.013       1.09          201
  55                   findobj             0.012       1.04            7
  78                   __get__             0.010       0.88          178
  81            __fieldnames__             0.007       0.64          317
   2                     print             0.007       0.63            1
 101 imformats>default_formats             0.003       0.25            1
   3      __print_parse_opts__             0.003       0.22            1
  59                   strcmpi             0.002       0.18          409
Elapsed time is 0.0467479 seconds.
   #             Function Attr     Time (s)   Time (%)        Calls
-------------------------------------------------------------------
  27              findobj             0.011      23.54            7
  54              __get__             0.010      21.28          178
  57       __fieldnames__             0.007      15.26          317
  93              drawnow             0.005       9.90            3
  26                  set             0.003       6.58           42
  16                  get             0.002       4.66          201
  32              strcmpi             0.002       4.22          409
  55           fieldnames             0.001       2.90          317
   2                print             0.001       2.09            1
   3 __print_parse_opts__             0.001       1.82            1




(file #56307)

Rik <rik5>
Group administrator
Wed 24 Jul 2024 03:26:44 PM UTC, comment #6: 

The process for printing figures to *latex* devices is to first rewrite all text objects (including labels and ticks) using the latex interpreter so that we know the correct extent of words (layout by latex with the correct font, size, ... freetype is not an option here) and can place them appropriately (e.g. the ticks and labels at the right distance from the axes lines).

Now on the original figure, I count only 11 distinct text strings (ticks), since all xyz labels are empty. So that leaves an open question: how is it that latex is called 41 times?

Pantxo Diribarne <pantxo>
Group Member
Wed 24 Jul 2024 10:06:22 AM UTC, comment #5: 

I compiled a debug version of the development sources and tried using callgrind to work out what is going on. I noticed that
run_command_and_return_output() was called 123 times. With gdb I could see that this is 41 calls to latex, dvisvgm and pvipng. The back-trace shows that these are called from a function called get_extent(). I don't pretend to have much idea what is going on here but if you want to know the glyph bounding box for typesetting:
1. If it is an outline font supported by FreeType then call into the library linked with octave
2. If you absolutely, positively MUST use a metafont font then the TeX distribution should have the corresponding tfm file so find it and parse that. If the tfm file doesn't exist then call the metafont interpreter, mf, to generate it.

Robert Jenssen <morgawr>
Wed 24 Jul 2024 07:18:24 AM UTC, comment #4: 

This is due to Octave having to render each tick label with the latex renderer the first time. The second time, it uses the cached images and is thus much faster.  I don't think we can do anything, except maybe throw a warning the first time the user tries to use a latex devices, e.g.: "warning: rendering all text labels with latex. This may take some time."

Pantxo Diribarne <pantxo>
Group Member
Wed 24 Jul 2024 01:50:08 AM UTC, comment #3: 

I tried compiling 9.2.1 with Qt5 (on Centos Stream 9) and also tried to recompile Fedora's rpm on that computer. all 3
(9.2.1 w/ Qt6, 9.2.1/Qt5, Fedora's 8.4.0 w/ Qt5) produce nearly identical results 9.6/ 0.8 seconds.

Dmitri.
--


Dmitri A. Sergatskov <dasergatskov>
Wed 24 Jul 2024 01:19:21 AM UTC, comment #2: 

I can (kind of) reproduce OP results on Fedora 40.
With 9.2.1 I get 8.75sec/0.27sec and with Fedora provided
octave 8.4 5.94sec/0.35sec

This is on 5-years old laptop (i9-9880h).

Fedora's octave is compiles against Qt5, in case it might be important.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 23 Jul 2024 11:54:48 PM UTC, comment #1: 

The first print is always slow, but I don't have any regression.  I tried the development branch (10.1), current stable (9.2), and older versions (8.4, 7.3) and the ratio of the first timing to the second timing is always ~20.

Maybe other programmers can try the test script and see if they notice a difference on their machines.

I'm attaching a version of print_latex_test.m so that it can just be downloaded and run.

(file #56299)

Rik <rik5>
Group administrator
Mon 22 Jul 2024 11:36:32 AM UTC, original submission:  

I use a local build of octave-9.2.0 with qt-6. The _octave_config_info_ is attached.

Printing a random plot to the pdflatex device is slow:

$ cat src/test/print_latex_test.m
% print_latex_test.m

profile on

version

tic;
x=rand(1000,1);
plot(x);
print("x","-dpdflatex");
close;
toc;

tic;
x2=rand(1000,1);
plot(x2);
print("x2","-dpdflatex");
close;
toc;

profile off
profshow(5)

$ octave -q --no-gui src/test/print_latex_test.m
ans = 9.2.0-robj
Elapsed time is 17.7439 seconds.
Elapsed time is 0.412699 seconds.
   #      Function Attr     Time (s)   Time (%)        Calls
------------------------------------------------------------
  39           set    R       12.269      67.61          122
  21           get             5.078      27.98          538
  36 __go_uimenu__             0.231       1.27           48
 182 __go_delete__             0.214       1.18            2
 173       drawnow             0.164       0.90            6
Elapsed time is 17.5638 seconds.
Elapsed time is 0.415475 seconds.


The first plot takes 18s. The second plot in the session takes less than 1s.

For comparison, I installed the Fedora octave-8.4.0-6.fc40 package:

$ octave --no-gui -q src/test/print_latex_test.m
ans = 8.4.0
Elapsed time is 11.979 seconds.
Elapsed time is 0.412181 seconds.
   #      Function Attr     Time (s)   Time (%)        Calls
------------------------------------------------------------
  39           set    R        6.359      51.36          122
 173       drawnow             5.238      42.31            6
  36 __go_uimenu__             0.284       2.29           48
 182 __go_delete__             0.274       2.22            2
 133       findobj             0.043       0.35           14


Robert Jenssen <morgawr>

 

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

Attach Files:
   
   
Comment:
   

Attached Files
file #56307:  prof_latex.m added by rik5 (288B - text/x-objcsrc)
file #56299:  print_latex_test.m added by rik5 (185B - text/x-objcsrc)

 

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 (Updated the item)
  • -email is unavailable- added by morgawr (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
    2024-07-24 rik5 Attached File- Added prof_latex.m, #56307
    2024-07-24 pantxo CategoryPlotting Plotting with OpenGL
        StatusWorks For Me Confirmed
    2024-07-23 rik5 Attached File- Added print_latex_test.m, #56299
        StatusNone Works For Me
    2024-07-22 morgawr Attached File- Added _octave_config_info_.txt, #56296

    Back to the top

    Powered by Savane 3.14-f13d.
    Corresponding source code