bugGNU Octave - Bugs: bug #55225, building doc figures in .eps or...

 
 

bug #55225: building doc figures in .eps or .pdf format occasionally silently fails

Submitter:  Mike Miller <mtmiller>
Submitted:  Fri 14 Dec 2018 07:27:08 PM UTC
   
 
Category:  Plotting with OpenGL Severity:  3 - Normal
Priority:  5 - Normal Item Group:  Build Failure
Status:  Fixed Assigned to:  None
Originator Name:  Open/Closed:  * Closed
Release:  * dev Operating System:  * GNU/Linux
Fixed Release:  None Planned Release:  None
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Tue 20 Oct 2020 11:19:37 AM UTC, comment #63: 

The last few comments seem to be concerning a possible deadlock with the graphics subsystem. That is tracked in bug #58678 IIUC.

The original issue seems to be fixed. At least, I'm not aware of recent reports about failing to create the figures for the documentation.

Closing as fixed.

Markus Mützel <mmuetzel>
Group administrator
Mon 29 Jun 2020 09:36:55 PM UTC, comment #62: 

@jwe: bug #58678 suggests that using BlockingQueuedConnection to initialize and finalize objects is not safe. Could the copy-on-write approach you talked about in https://savannah.gnu.org/bugs/index.php#comment44 help solving this?

For reminder, the reason why I chose to synchronize threads this way are:

  • qt_graphics_toolkit::print_figure: we want to be sure the printout file is ready when drawnow returns. This is necessary e.g. for:



plot (1:10)
print -dpdflatexstandalone toto
system "pdflatex toto"


  • qt_graphics_toolkit::get_pixels: this function must return pixels from the GUI thread where they are drawn


  • qt_graphics_toolkit::finalize: we want to make sure that the reference to the graphics objects held by the GUI Object is released when we return. This way we can use the graphics destructor of the graphics_object to trigger some cleanup actions like with uicontextmenu (see bug #58403)


  • qt_graphics_toolkit::initialize: we want to be sure the GUI Object has been created when one of the above functions is called otherwise this bug can happen (invokeMethod fails).


I think first and second points can be circumvented by drawing on an FBO in the interpreter thread.

Pantxo Diribarne <pantxo>
Group Member
Mon 29 Jun 2020 08:34:04 PM UTC, comment #61: 

I just posted a new bug report (bug #58678) that shows that it is quite easy to deadlock with the approach I have used in qt_graphics_toolkit::initialize and finalize. I hadn't anticipated that we could be using recursive mutexes.

Pantxo Diribarne <pantxo>
Group Member
Sun 28 Jun 2020 02:16:26 PM UTC, comment #60: 

@Markus: Sorry, looks like I have sent a buggy patch. With the patch from comment #58 GUI objects fail to initialize due to a missing argument to create_object. I'll provide an updated patch when I get some time.

Pantxo Diribarne <pantxo>
Group Member
Sat 27 Jun 2020 11:07:29 AM UTC, comment #59: 

The deadlock on the buildbot seems to have been a single time occurrence so far.
Nevertheless, the changes in the patch attached to comment #58 seem reasonable to me.

I applied that changeset on top of 6bd9d77c7105. But during make all -j3 (while the system was loaded with compiling MXE Octave with 3 jobs as well), I got the following errors:

error: ObjectProxy::print: invalid GUI Object
error: called from
    __opengl_print__ at line 206 column 9
    print at line 759 column 16
    geometryimages at line 63 column 5
make[2]: *** [Makefile:31204: doc/interpreter/voronoi.eps] Error 1
make[2]: *** Waiting for unfinished jobs....
error: ObjectProxy::print: invalid GUI Object
error: called from
    __opengl_print__ at line 206 column 9
    print at line 759 column 16
    geometryimages at line 70 column 5
make[2]: *** [Makefile:31206: doc/interpreter/triplot.eps] Error 1


I'm not sure if this is something caused by that changeset. Or some error that is revealed with that change. Or something completely unrelated...

Markus Mützel <mmuetzel>
Group administrator
Sun 07 Jun 2020 01:40:59 PM UTC, comment #58: 

If this is the first deadlock in a while and it happens in the middle of a test which creates graphics objects ... then I would be astonished if it was not provoked by the changes in  cset a379987a74b0.

Another way to have a deadlock (apart from the one in comment #56) is if we use a BlockingQueuedConnection to execute a slot in the same thread as the signal [1].

When initializing the qt_graphics_toolkit (in graphics-init.cc) we use QObject::moveToThread to force the thread affinity of the qt_graphics_toolkit, but we don't check it has taken effect at the time we initialize our first Object.

From Qt's doc on QObject::moveToThread [1]:

>> A QEvent::ThreadChange event is sent to this object just before the thread affinity is changed.

 
The attached cset makes sure a deadlock due to wrong thread affinity cannot happen, but doesn't fix the fact that the qt_graphics_toolkit may not be ready (attached to the GUI thread) when the first object initialization is requested.


[1] https://doc.qt.io/qt-5/qt.html#ConnectionType-enum
[2] https://doc.qt.io/qt-5/qobject.html#moveToThread

(file #49222)

Pantxo Diribarne <pantxo>
Group Member
Sat 06 Jun 2020 08:29:31 PM UTC, comment #57: 

It looks like a deadlock occurred during the BISTs for "ishandle" on the clang-4.0-debian buildbot:
http://buildbot.octave.org:8010/#/builders/10/builds/1560/steps/7/logs/stdio

I don't know if it is related to the changes here.

Markus Mützel <mmuetzel>
Group administrator
Tue 02 Jun 2020 10:29:55 PM UTC, comment #56: 


>> Is there any chance that using this method can cause a deadlock?


The only way I know of to provoke a deadlock is if we block the interpreter thread while it owns the graphics mutex, and we try to lock the mutex from the GUI thread.

We should thus make sure, prior to executing methods in the GUI thread, that the interpreter thread does not own the graphics mutex:

  • In qt_graphics_toolkit::initialize and qt_graphics_toolkit::finalize we have this construct:



    // FIXME: We need to unlock the mutex here but we have no way to know if
    // if it was previously locked by this thread, and thus if we should
    // re-lock it.

    gh_manager& gh_mgr = m_interpreter.get_gh_manager ();

    gh_mgr.unlock ();

    ...


  • As for qt_graphics_toolkit::print_figure, it is currently only called from Fdrawnow after explicitly unlocking the graphics mutex.



          gh_mgr.unlock ();

          go.get_toolkit ().print_figure (go, term, file, debug_file);

          gh_mgr.lock ();


  • And finally qt_graphics_toolkit::get_pixels: it is currently only called from F__get_pixels__ which doesn't lock the mutex.


We need to harmonize this all.

I think it would be easier to avoid the construct from Fdrawnow, where the caller has to know that qt_graphics_toolkit::xxx_method needs to be executed while the mutex is unlocked. Instead, the caller should just expect qt_graphics_toolkit::xxx_method to do its job and return with the state of the mutex unchanged.

The problem (see FIXME note in above code) is that the gh_manager does not seem to provide a way to know if the mutex is currently locked by this (interpreter) thread.

Pantxo Diribarne <pantxo>
Group Member
Tue 02 Jun 2020 02:38:06 PM UTC, comment #55: 

My apologies for undoing the blocking connection more than once.

Is there any chance that using this method can cause a deadlock?

John W. Eaton <jwe>
Group administrator
Tue 02 Jun 2020 02:20:22 PM UTC, comment #54: 
Pantxo Diribarne <pantxo>
Group Member
Mon 01 Jun 2020 09:20:43 PM UTC, comment #53: 

@Markus: the errors are raised from the interpreter thread, where the object proxy lives, so there should be no problem handling them.

I'll push the patch to stable if no one opposes. It mostly reverts an unintended change during the development process.

Pantxo Diribarne <pantxo>
Group Member
Mon 01 Jun 2020 08:30:36 PM UTC, comment #52: 

Very encouraging, thanks to everyone for all the hard work investigating, fixing, and testing this.

I was curious about the history, so I thought I'd document this here in case it's useful later.

This bug was first fixed and closed in December 2018 with the same fix as bug #55226 (https://hg.savannah.gnu.org/hgweb/octave/rev/5535267e88ba), and that fix is part of version 5.2.0.

This bug then reappeared in August 2019 with the refactoring of the qt graphics toolkit (https://hg.savannah.gnu.org/hgweb/octave/rev/ae53e56e16f2).

It currently affects both the stable and default branches, but no tagged releases yet.

Mike Miller <mtmiller>
Group Member
Mon 01 Jun 2020 07:36:03 PM UTC, comment #51: 

Running "dump_plot_demos" finally finished (took about 2 hours on Windows). No errors here.
So from what I can tell, your patch looks good.

Markus Mützel <mmuetzel>
Group administrator
Mon 01 Jun 2020 09:13:34 AM UTC, comment #50: 

I wasn't affected by the original bug. So I don't know if any testing on my part is of much help.
But I went ahead anyway and applied your patch on top of hg id 28676df1deaf locally.
After compiling with it, I ran the dump_plot_demos script from the GUI with the qt toolbox. I thought that this might be a good test because it creates and destroys a lot of graphics objects. (Please let me know if it doesn't test the changes.)
With this test, there don't seem to be any negative side effects on my side.

I'll try with a Windows build next. But - as always - it might take a little to cross-compile.

As for the question of using "error" or "warning_with_id": I'm probably not the most qualified person to comment. But I believe to remember that issues with emitting errors in the GUI thread have been fixed in the past. So I think it should be ok to raise errors in the GUI thread in general.
Also IIUC, having an invalid "m_object" in the ObjectProxy will most likely cause problems later on anyway. So erroring out early sounds reasonable to me.
However, if you are in doubt, maybe it would be safest to push the changes using "warning_with_id" to stable, merge to default and push another change to replace "warning_with_id" with "error" on default. (Or push the patch as is to default, graft to stable and replace "error" with "warning_with_id" on stable.)

Markus Mützel <mmuetzel>
Group administrator
Wed 27 May 2020 09:27:35 PM UTC, comment #49: 

@jwe: The attached patch adds a comment to explain that we need to use a blocking connection when creating GUI objects and their proxy.

In order to be able to report errors when we finally fail to execute the  slotPrint, I used the invokeMethod construct rather than signal/slot connection.

After this change, ObjectProxy::finalize, ObjectProxy::get_pixels, ObjectProxy::print raise an error if they are called with an invalid GUI Object or if invokeMethod failed. Is it OK to raise an error? Or should I use a warning with id?

(file #49181)

Pantxo Diribarne <pantxo>
Group Member
Wed 27 May 2020 12:25:22 PM UTC, comment #48: 

It was probably me, trying to fix the crash on exit problem.

Probably it would be good to add some comments explaining why we need special connection types any time we don't use the defaults (I need to remember to do that as well).

John W. Eaton <jwe>
Group administrator
Wed 27 May 2020 12:20:06 PM UTC, comment #47: 

The problem with this patch is that already did that change


http://hg.savannah.gnu.org/hgweb/octave/rev/5535267e88ba

... but it looks like someone reverted it. I'll play with "hg blame" to see what cset reverted that change and hopefully determine the reason.

Pantxo Diribarne <pantxo>
Group Member
Tue 26 May 2020 05:05:21 PM UTC, comment #46: 

confirmed

Hg200 <hg200>
Tue 26 May 2020 11:04:07 AM UTC, comment #45: 

This patch fixes the problem for me.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 26 May 2020 07:49:30 AM UTC, comment #44: 

@Hg200: You are right, the slot never gets called.

I drew my previous erroneous conclusions while using a patch (attached as tst_print.patch) that changes the way we execute the slots. 

I used the following for testing


rm -rf /tmp/t1/*
rm -rf /tmp/tst_print.log
parallel -j 32 -N0 -q ./run-octave --norc --silent --no-history --eval 'figure ("visible", "off"); plot ([1,2]); pipeline = ["/tmp/t1/file-" num2str({#}) ".ps"]; drawnow ("eps", pipeline);' ::: {1..256} > /tmp/tst_print.log 2> /dev/null
ls -c /tmp/t1/ | wc -l


With this patch I see that:

  • the ObjectProxy pointer is always valid in qt_graphics_toolkit::print_figure (so I was still wrong): "failed "is never printed
  • sometimes "Sending print" (and the rest) is not printed: so it means that the problem is that the proxy is not fully constructed and doesn't hold a valid Figure Object (m_object member).


My conclusion is that making the initialization of ObjectProxy synchronous would probably solve this, at least it does for me with the second attached patch.


(file #49171, file #49172)

Pantxo Diribarne <pantxo>
Group Member
Mon 25 May 2020 07:58:34 PM UTC, comment #43: 

I don't doubt Pantxo's results. However, I want to share what I see on my computer because it looks a little different. The following modifications write to /tmp/t1/ when run with the script from comment #41 and based on the number of files written, we can see where the data is lost.

1.) A number of 128 .txt files are written here. I can't detect any nullptrs:

  void
  qt_graphics_toolkit::print_figure (const graphics_object& go,
                                     const std::string& term,
                                     const std::string& file_cmd,
                                     const std::string& /*debug_file*/) const
  {
    ObjectProxy *proxy = toolkitObjectProxy (go);

    if (proxy)
      proxy->print (QString::fromStdString (file_cmd),
                    QString::fromStdString (term));

    char str[80];
    FILE *fid;
    sprintf (str, "%s.txt", file_cmd.c_str());
    fid = fopen (str, "w");
    fprintf (fid, "%p\n", proxy);
    fclose (fid);
  }


2.) A number of 128 .txt files are written here. Therefore the signal must be emitted 128 times.

  void
  ObjectProxy::print (const QString& file_cmd, const QString& term)
  {
    emit sendPrint (file_cmd, term);

    char str[80];
    FILE *fid;
    sprintf (str, "%s.txt", file_cmd.toUtf8().constData());
    fid = fopen (str, "w");
    fclose (fid);
  }


3.) If we write files in the slot we have less 128 files. So here is the loss:

  void
  Object::slotPrint (const QString& file_cmd, const QString& term)
  {
    gh_manager& gh_mgr = m_interpreter.get_gh_manager ();

    octave::autolock guard (gh_mgr.graphics_lock ());

    if (object ().valid_object ())
      print (file_cmd, term);

    char str[80];
    FILE *fid;
    sprintf (str, "%s.txt", file_cmd.toUtf8().constData());
    fid = fopen (str, "w");
    fclose (fid);
  }


Therefore my tip would be that it is not gl2ps. I would rather say either the slots are not connected in ObjectProxy::init () or we have a thread problem.


connect (this, SIGNAL (sendPrint (const QString&, const QString&)), m_object, SLOT (slotPrint (const QString&, const QString&)), Qt::BlockingQueuedConnection);


Hg200 <hg200>
Sun 24 May 2020 05:33:54 PM UTC, comment #42: 

With the help of the code from comment #41, I was able to reproduce the bug repeatedly.

The problem comes from this construct:


qt_graphics_toolkit::print_figure (const graphics_object& go,
                                     const std::string& term,
                                     const std::string& file_cmd,
                                     const std::string& /*debug_file*/) const
  {
    ObjectProxy *proxy = toolkitObjectProxy (go);

    if (proxy)
      proxy->print (QString::fromStdString (file_cmd),
                    QString::fromStdString (term));
  }


Sometimes toolkitObjectProxy returns a nullptr and the print operation is silently skipped without error.


Pantxo Diribarne <pantxo>
Group Member
Sun 24 May 2020 04:22:29 PM UTC, comment #41: 

I can also confirm this. Here is a variant of the code from comment #34 that just calls drawnow (all ghostscript rubbish removed). produces 110 files of 128 when I play with mozilla at the same time.


rm -rf /tmp/t1/*
parallel -j 32 -N0 -q ./run-octave --norc --silent --no-history --eval 'plot ([1,2]); pipeline = ["/tmp/t1/file-" num2str({#}) ".ps"]; drawnow ("eps", pipeline);' ::: {1..128}
ls -c /tmp/t1/ | wc -l


Hg200 <hg200>
Sun 24 May 2020 01:13:10 PM UTC, comment #40: 

You just open it in text editor...
It looks OK. I also realized that we pipe it through ghostscript.
So I changed the output file to svg.
The problem is still there. With gnuplot I get 128 files in 2.7 sec; with opengl I got 92 in 13.3 sec.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Sun 24 May 2020 12:54:23 PM UTC, comment #39: 

Not sure how to read the header. So I'll attach one of the generated .ps files.

(file #49161)

Markus Mützel <mmuetzel>
Group administrator
Sun 24 May 2020 12:48:16 PM UTC, comment #38: 

Are you sure you are using OpenGL backend when you run the test?
(You can inspect the header for the ps output files to make sure).
If I unset DISPLAY (so the gnuplot backend would be used, then
it makes all 128 files as intended; also it runs about 2x faster.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Sun 24 May 2020 12:33:30 PM UTC, comment #37: 

I'm not sure how write caching works on Linux. But I suppose that it is dependent on (parallel) disc access.

I can't reproduce the issue even for very high numbers of parallel jobs. When I check the write cache with hdparm, I see the following:

$ sudo hdparm -W /dev/sda

/dev/sda:
 write-caching = not supported


Is this the same for you?
Could you try disabling the write for the drive that holds your tmp directory and see whether that makes any difference?
Not sure if this is the right command:

sudo hdparm -W0 /dev/sda


Markus Mützel <mmuetzel>
Group administrator
Sun 24 May 2020 11:41:47 AM UTC, comment #36: 

If it is buffering then serial build would fail as well. It succeeds. My pure speculation is that this is a race condition
with access to GL buffer.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Sun 24 May 2020 11:02:11 AM UTC, comment #35: 

I wonder if this is (at least partly) a buffering issue.
There are also errors of this kind that might be related (e.g. http://buildbot.octave.org:8010/#/builders/9/builds/1559/steps/5/logs/stdio ):

error: print: error opening file 'extended.tex'
error: called from
    print>latex_standalone at line 1026 column 5
    __opengl_print__ at line 214 column 5
    print at line 759 column 16
    plotimages at line 109 column 7


Maybe "sync" at some crucial points in the pipeline could help?

Markus Mützel <mmuetzel>
Group administrator
Sat 23 May 2020 05:00:02 AM UTC, comment #34: 

See also bug 56952 (recent comments).
Essentially:

rm -rf /tmp/t1/*

parallel -j 32 -N0 -q ./run-octave --norc --silent --no-history --eval 'plot (1:2); print(tempname("/tmp/t1", "t1-"));' ::: {1..128}

ls -c /tmp/t1/ | wc -l
88

(I expected it to be 128)

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Fri 22 May 2020 06:54:35 PM UTC, comment #33: 

Pantxo: I created a shim shell script 'epstool' that calls the real epstool program and writes the command line and exit status to a log file:


#!/bin/sh
/usr/bin/epstool "$@"
status=$?
echo "$(date "+%b %d %H:%M:%S.%N") /usr/bin/epstool $@ exited with status $status" >> $HOME/epstool-runs.log
exit $status


I reproduced this problem again by deleting all images in doc/interpreter and running make again. There are a total of 27 expected images. I got 27 .pdf, .png, and .txt files, but only 25 .eps files. The two missing files this time were 'inpolygon.eps' and 'mesh.eps'. Neither of those files are listed in the file ~/epstool-runs.log, the epstool program was only called by Octave 25 times.

So it appears to me that the problem is somewhere in Octave / gl2ps, before it gets to the point when it calls the epstool pipeline. Any ideas where to look next?

Mike Miller <mtmiller>
Group Member
Wed 19 Feb 2020 08:51:54 PM UTC, comment #32: 

@Mike: I am not able to reproduce this reliably (only once in many trials) and have no idea how to debug this.

When printing to EPS and PDF formats we essentially produce an eps contents, using gl2ps, which we pipe to epstool or ghostscript for final adjustment/conversion.

Note that epstool also calls Ghostscript in the background, so I guess that in certain conditions Ghostscript fails to produce the output file and doesn't report an error.

Pantxo Diribarne <pantxo>
Group Member
Tue 18 Feb 2020 07:55:12 PM UTC, comment #31: 

Pantxo - do you have any ideas what I can do to test or debug further to determine why Octave sometimes doesn't write an image file at all when running interpimages.m or plotimages.m or the others in batch mode? I can reproduce this on my system very easily, but I can't help fix this.

Mike Miller <mtmiller>
Group Member
Mon 17 Feb 2020 09:09:22 PM UTC, comment #30: 

This still affects me on the default branch (Octave 7) today:

+verbatim+
-verbatim-
$ make all
...
  GEN      doc/interpreter/extended.eps
  GEN      doc/interpreter/gplot.eps
  GEN      doc/interpreter/grid.eps
...
  TEXI2DVI doc/interpreter/octave.dvi
/usr/bin/texi2dvi: etex exited with bad status, quitting.
...
$ ls -l doc/interpreter/[eg]*.eps
-rw-r--r-- 1 mike mike  19563 Feb 17 12:51 doc/interpreter/errorbar.eps
-rw-r--r-- 1 mike mike 655555 Feb 17 12:51 doc/interpreter/griddata.eps
-rw-r--r-- 1 mike mike  25608 Feb 17 13:04 doc/interpreter/grid.eps
$
-verbatim-

Building again repeatedly eventually builds all .eps image files and octave.dvi is then built successfully.

Mike Miller <mtmiller>
Group Member
Fri 15 Nov 2019 12:21:17 AM UTC, comment #29: 

Yeah, so the important error messages buried in those 600 lines are


No file octave.cps.
No file octave.fns.
No file octave.ops.
No file octave.prs.


Your error is unrelated to this bug, and is probably due to a problem in texinfo's texindex. Like I said on the mailing list, I used to see this error randomly on Debian some number of weeks / months ago, but it's gone away for me, probably fixed by a newer version of texinfo. If you want you can open a new bug report, but the fix may end up being to avoid particular versions of texinfo. Which would be good to know in general.

Mike Miller <mtmiller>
Group Member
Thu 14 Nov 2019 11:16:17 PM UTC, comment #28: 

It seems like it's the latter for me, that octave.dvi always fails to build.

Attached is the verbose log.

(file #47870)

Nir Krakauer <nir_krakauer>
Thu 14 Nov 2019 09:40:48 PM UTC, comment #27: 

The easiest way to tell if you are hitting this bug is to try 'make all' again. If it's this bug, you will see something like


...
  GEN      doc/interpreter/interpft.eps
  TEXI2DVI doc/interpreter/octave.dvi


and then octave.dvi will build successfully. Keep repeating until all images are built and exist, and eventually octave.dvi will build without error.

If you run 'make' again and it only tries to build octave.dvi and it fails again and again, then it's probably not this bug, but a different problem.

You can always get the full output from texi2dvi and TeX by running 'make V=1' or looking in doc/interpreter/octave.t2d/doc!interpreter!octave.t2d/dvi/build/octave.log.

Mike Miller <mtmiller>
Group Member
Thu 14 Nov 2019 08:57:23 PM UTC, comment #26: 

I'm not sure. I don't see any message about an EPS file not existing. It's basically just


  TEXI2DVI doc/interpreter/octave.dvi
/usr/bin/texi2dvi: etex exited with bad status, quitting.


Nir Krakauer <nir_krakauer>
Thu 14 Nov 2019 07:35:33 PM UTC, comment #25: 

The Texinfo version shouldn't matter if this is the same bug.

Nir - are you sure you are experiencing this bug? Specifically, do you see make report that it's building, for example, interpft.eps, followed by an error building octave.dvi, and then you can confirm that interpft.eps doesn't exist?

The specific symptom that this bug report is about is not just Texinfo failing to build for some reason (like in your message to the mailing list), but that Octave is asked to build an image file in doc/interpreter, it exits with success, make continues, but the image file was not actually generated.

Mike Miller <mtmiller>
Group Member
Thu 14 Nov 2019 07:31:52 PM UTC, comment #24: 

`texi2dvi --version` gives `6.6`

Nir Krakauer <nir_krakauer>
Thu 14 Nov 2019 07:17:12 PM UTC, comment #23: 

Nir -- What is your texinfo version?

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Thu 14 Nov 2019 07:12:14 PM UTC, comment #22: 

I experienced the same error with both `-j2` and `-j1`, cf. https://octave.1599824.n4.nabble.com/Problem-building-Octave-td4694553.html

Nir Krakauer <nir_krakauer>
Wed 16 Oct 2019 07:04:33 PM UTC, comment #21: 

This happens with buildbot as well. E.g.:

http://buildbot.octave.org:8010/#/builders/11/builds/1162/steps/5/logs/stdio

Dmitri.

Dmitri A. Sergatskov <dasergatskov>
Wed 16 Oct 2019 06:34:24 PM UTC, comment #20: 

This bug still affects me. Right now, this is very highly reproducible for me, and it seems highly correlated to building with "make -jN". However, I am still sometimes able to reproduce this with serial "make -j1".

Here are some examples from my current build tree, using a sampling of image files that happened to fail to build for me:


## parallel build

$ rm -f doc/interpreter/{convhull,errorbar,hist,mesh,polar}.eps
$ make -j8 doc/interpreter/{convhull,errorbar,hist,mesh,polar}.eps
  GEN      doc/interpreter/convhull.eps
  GEN      doc/interpreter/errorbar.eps
  GEN      doc/interpreter/hist.eps
  GEN      doc/interpreter/mesh.eps
  GEN      doc/interpreter/polar.eps
$ ls -l doc/interpreter/{convhull,errorbar,hist,mesh,polar}.eps
ls: cannot access 'doc/interpreter/errorbar.eps': No such file or directory
ls: cannot access 'doc/interpreter/mesh.eps': No such file or directory
ls: cannot access 'doc/interpreter/polar.eps': No such file or directory
-rw-r--r-- 1 mike mike 17553 Oct 16 11:29 doc/interpreter/convhull.eps
-rw-r--r-- 1 mike mike 13134 Oct 16 11:29 doc/interpreter/hist.eps

## serial build

$ rm -f doc/interpreter/{convhull,errorbar,hist,mesh,polar}.eps
$ make -j1 doc/interpreter/{convhull,errorbar,hist,mesh,polar}.eps
  GEN      doc/interpreter/convhull.eps
  GEN      doc/interpreter/errorbar.eps
  GEN      doc/interpreter/hist.eps
  GEN      doc/interpreter/mesh.eps
  GEN      doc/interpreter/polar.eps
$ ls -l doc/interpreter/{convhull,errorbar,hist,mesh,polar}.eps
ls: cannot access 'doc/interpreter/errorbar.eps': No such file or directory
-rw-r--r-- 1 mike mike  17553 Oct 16 11:31 doc/interpreter/convhull.eps
-rw-r--r-- 1 mike mike  13134 Oct 16 11:31 doc/interpreter/hist.eps
-rw-r--r-- 1 mike mike 839976 Oct 16 11:31 doc/interpreter/mesh.eps
-rw-r--r-- 1 mike mike  19259 Oct 16 11:31 doc/interpreter/polar.eps


As you can see, Octave does not report an error when the command fails to produce a .eps file, and it exits with success, so there is no indication to make that anything failed. The error is caught later when octave.dvi fails to build.

Mike Miller <mtmiller>
Group Member
Mon 18 Mar 2019 11:26:13 PM UTC, comment #19: 

I filed bug #55952 for the "seealso already defined" build error.

Mike Miller <mtmiller>
Group Member
Mon 18 Mar 2019 11:17:05 PM UTC, comment #18: 

On a second look, this is just your build directory, so the problem must be somewhere else...

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Mon 18 Mar 2019 11:12:17 PM UTC, comment #17: 

Neither buildbots nor me have sundials 4.x so we do not see this problem...

Dmitri.
--


Dmitri A. Sergatskov <dasergatskov>
Mon 18 Mar 2019 10:42:58 PM UTC, comment #16: 

I'm hitting the same error as Stefan now in my last build


../doc/interpreter/macro
s.texi:51: Macro name seealso already defined.
@macroxxx ...@the @macname @space already defined}
                                                  @fi @global @cslet {macsav...
l.51 @macro seealso {args}

? ^C/home/mike/src/octave/default/+build-default-sundials4/../doc/interpreter/macro
s.texi:51: Interruption.
<to be read again>
                   @global
@macroxxx ...e @space already defined}@fi @global
                                                  @cslet {macsave.@the @macn...
l.51 @macro seealso {args}

?


Aside from the top-level error being the same "/usr/bin/texi2dvi: etex exited with bad status, quitting.", this does not look like the same bug that this report is about.

Mike Miller <mtmiller>
Group Member
Mon 18 Mar 2019 05:48:32 PM UTC, comment #15: 

Make sure you do not have corrupted files left over from previous failed builds. Start with a fresh new clone...

Dmitri.

Dmitri A. Sergatskov <dasergatskov>
Mon 18 Mar 2019 05:32:29 PM UTC, comment #14: 

With -j1 V=1 I now get this:

'''
texi2dvi  --build-dir=doc/interpreter/octave.t2d -o doc/interpreter/octave.dvi  \
`test -f 'doc/interpreter/octave.texi' || echo '/home/haawda/paketierung/meine_Pakete/octave-hg/src/octave/build/../'`doc/interpreter/octave.texi
This is pdfTeX, Version 3.14159265-2.6-1.40.20 (TeX Live 2019) (preloaded format=etex)
 restricted \write18 enabled.
entering extended mode

(/home/haawda/paketierung/meine_Pakete/octave-hg/src/octave/build/../doc/interp
reter/octave.texi
(/home/haawda/paketierung/meine_Pakete/octave-hg/src/octave/build-aux/texinfo.t
ex Loading texinfo [version 2019-03-16.20]: pdf, fonts, markup, glyphs,
page headings, tables, conditionals, indexing, sectioning, toc, environments,
defuns, macros, cross references, insertions,
(/usr/local/texlive/2019/texmf-dist/tex/generic/epsf/epsf.tex
This is `epsf.tex' v2.7.4 <14 February 2011>
) localization, formatting, and turning on texinfo input format.)
(/home/haawda/paketierung/meine_Pakete/octave-hg/src/octave/build/../doc/interp
reter/macros.texi
/home/haawda/paketierung/meine_Pakete/octave-hg/src/octave/build/../doc/interpr
eter/macros.texi:51: Macro name seealso already defined.
@macroxxx ...@the @macname @space already defined}
                                                  @fi @global @cslet {macsav...
l.51 @macro seealso {args}
                         
?

Stefan Husmann <haawda>
Tue 12 Mar 2019 09:03:18 PM UTC, comment #13: 

Here is what I see in logs:


Mar 11 17:15:48 amd systemd-coredump[23808]: Process 22665 (lt-octave-gui) of user 1002 dumped core.

                                             Stack trace of thread 22665:
                                             #0  0x00007f9aea6b26a0 n/a (n/a)
                                             #1  0x00007f9b09b1d285 _ZN19QApplicationPrivate13notify_helperEP7QObjectP6QEvent (libQt5Widgets.so.5)
                                             #2  0x00007f9b09b249a0 _ZN12QApplication6notifyEP7QObjectP6QEvent (libQt5Widgets.so.5)
                                             #3  0x00007f9b0b7b6660 n/a (/home/buildbotu/fc25-x86_64/clang-fedora/build/libgui/.libs/liboctgui.so.5.0.0)
Mar 11 17:15:48 amd audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-coredump@13-23806-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=?>
Mar 11 17:15:49 amd abrt-server[23862]: Deleting problem directory ccpp-2019-03-11-17:15:48.614346-22665 (dup of ccpp-2019-02-20-16:56:03.416525-6133)
Mar 11 17:15:50 amd abrt-notification[23915]: Process 6133 (lt-octave-gui) crashed in ??()
Mar 11 17:15:55 amd qcollectiongenerator-qt5[24063]: QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-buildbotu'


Dmitri.

Dmitri A. Sergatskov <dasergatskov>
Tue 12 Mar 2019 08:15:26 PM UTC, comment #12: 

I suspect that it happens when computer is heavily loaded. The buildbots running multiple parallel builds when this happens.
I cannot reproduce it if I just re-run make on this computer.

(You can also see that this is not a single occurence:
http://buildbot.octave.org:8010/#/builders/9
)

Dmitri.

Dmitri A. Sergatskov <dasergatskov>
Tue 12 Mar 2019 06:09:04 PM UTC, comment #11: 

Marking the bug confirmed, even though I can't reproduce, and reopening this report.

Pantxo Diribarne <pantxo>
Group Member
Tue 12 Mar 2019 06:07:38 PM UTC, comment #10: 

It looks like creating and destroying ui objects synchronously was not a definite fix, but rather made this bug less probable.

This shows that the issue was clearly not what I though it was (I was sure this bug could simply not happen anymore). Furthermore the synchronous approach made things slower. I'll work on this when I find some time.

@Dmitri: It is strange that creating txt files (that don't even involve creating a figure) crash Octave. This may be a different issue.

Pantxo Diribarne <pantxo>
Group Member
Tue 12 Mar 2019 05:00:08 PM UTC, comment #9: 

Some buildbots are crashing (with sigfault) too:

http://buildbot.octave.org:8010/#/builders/9/builds/770

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Tue 12 Mar 2019 03:16:21 PM UTC, comment #8: 

After some month where everythink worked as expected I now encounter this again, building from stable mercurial branch or from develop branch.

Stefan Husmann <haawda>
Fri 21 Dec 2018 06:57:32 PM UTC, comment #7: 

This is fixed for me with the current stable branch, thanks.

Mike Miller <mtmiller>
Group Member
Fri 21 Dec 2018 06:45:13 PM UTC, comment #6: 

The patch for bug #55926 has been pushed. Marking this one ready for test.

Pantxo Diribarne <pantxo>
Group Member
Mon 17 Dec 2018 07:19:42 PM UTC, comment #5: 

The patch for bug #55226 also fixes this bug for me.

Mike Miller <mtmiller>
Group Member
Fri 14 Dec 2018 08:50:49 PM UTC, comment #4: 

The bug.sh also fails for me:
...
51: -rw-rw-r--. 1 10512 Dec 14 14:49 doc/interpreter/plot.eps
52: -rw-rw-r--. 1 10512 Dec 14 14:49 doc/interpreter/plot.eps
53: -rw-rw-r--. 1 10512 Dec 14 14:49 doc/interpreter/plot.eps
54: ls: cannot access 'doc/interpreter/plot.eps': No such file or directory

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Fri 14 Dec 2018 08:46:13 PM UTC, comment #3: 

This is a problem even with 'make -j1' as I showed in the initial comment. Now it may still be a problem with system load causing some kind of racy timeout condition, and it may get worse with more build jobs running in parallel, but it is not specifically due to two simultaneous instances of Octave and not solved with '-j1'.

Updated shell script to test this more easily with different figures and different file formats:


#!/bin/sh
# bug.sh
d=doc/interpreter
e=eps
f=plot
n=1
o=./run-octave
s=plotimages
fn="$d/$f.$e"
touch $fn
while [ -e $fn ]; do
  rm -f $fn \
    && $o -qfH --path ../$d --eval "$s ('$d/', '$f', '$e');" \
    && echo -n "$n: " \
    && ls -lgo $fn \
    && n=$((n+1))
done


With this I am able to observe that I get the same type of failure with the file format set to either eps or pdf. With either format, after some number of iterations, Octave silently fails to write the intended output file and exits with success.

There is a similar but different error with png format figures that I will report separately.

Mike Miller <mtmiller>
Group Member
Fri 14 Dec 2018 08:34:22 PM UTC, comment #2: 

I wonder if it is related to the problem I see with parallel builds. It seems to be hardware dependent. It is almost 100%
reproduciable on i5-4570 (Intel GPU) and Nehalem Xeon
(with Nvidia GPU though I use software rendering).

In my case it is always a problem with "make -j4" and even
"make -j4 V=1" fixes it. Building with gnuplot (instead of qt)
always works fine as well.

Dmitri.
--

Dmitri A. Sergatskov <dasergatskov>
Fri 14 Dec 2018 07:39:06 PM UTC, comment #1: 

As a follow up, the following shell script snippet also reveals this error pretty clearly for me


$ cat bug.sh
n=1
touch doc/interpreter/plot.eps
while [ -e doc/interpreter/plot.eps ]; do
  rm -f doc/interpreter/plot.eps \
    && ./run-octave -qfH --path ../doc/interpreter --eval "plotimages ('doc/interpreter/', 'plot', 'eps');" \
    && echo -n "$n: " \
    && ls -lgo doc/interpreter/plot.eps \
    && n=$((n+1))
done
$ ./bug.sh
1: -rw-r--r-- 1 10512 Dec 14 11:37 doc/interpreter/plot.eps
2: -rw-r--r-- 1 10512 Dec 14 11:37 doc/interpreter/plot.eps

39: ls: cannot access 'doc/interpreter/plot.eps': No such file or directory


There is no indication from Octave or from the shell exit status that anything went wrong, just that the file plot.eps doesn't exist.

Mike Miller <mtmiller>
Group Member
Fri 14 Dec 2018 07:27:08 PM UTC, original submission:  

On my system, building the figures for the user manual in the .eps format occasionally fails with no error message and no output file produced. The error only becomes apparent when octave.dvi is built, at which point TeX complains about the missing include file.

This is reproducible, although not 100% of the time, and is not always the same figures. The most recent example on my system:


$ rm -f doc/interpreter/*.{dvi,eps,pdf,png}
$ make -j1 V=1 all

…/doc/interpreter/poly.texi:838: Could not open file splinefit2.eps, ignoring it.

/usr/bin/texi2dvi: etex exited with bad status, quitting.


And sure enough, the file doc/interpreter/splinefit2.eps is missing. Scrolling up through the build output, I do see the following command


/bin/bash run-octave --norc --silent --no-history --path …/doc/interpreter/ --eval "splineimages ('doc/interpreter/', 'splinefit2', 'eps');"


With no error or indication that the command failed, simply no output file produced.

On a second or third repeat of the same sequence, it may work, or there may be a different set of 1 or 2 images missing.

This is with a real display, Intel integrated graphics, Qt toolkit, Qt 5.11.2, gl2ps 1.4.0.

Mike Miller <mtmiller>
Group Member

 

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

Attach Files:
   
   
Comment:
   

Attached Files
file #49222:  bug55225-4.patch added by pantxo (4KiB - text/x-patch)
file #49181:  bug55225-2.patch added by pantxo (6KiB - text/x-patch)
file #49171:  tst_print.patch added by pantxo (3KiB - text/x-patch)
file #49172:  bug55225.patch added by pantxo (1KiB - text/x-patch)
file #49161:  t1-0zCjk1.ps added by mmuetzel (164KiB - application/postscript)
file #47870:  buildlog1.txt added by nir_krakauer (28KiB - text/plain)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by jwe (Posted a comment)
  • -email is unavailable- added by hg200 (Posted a comment)
  • -email is unavailable- added by mmuetzel (Posted a comment)
  • -email is unavailable- added by nir_krakauer (Posted a comment)
  • -email is unavailable- added by haawda (Posted a comment)
  • -email is unavailable- added by pantxo (Posted a comment)
  • -email is unavailable- added by haawda (same here)
  • -email is unavailable- added by dasergatskov (Posted a comment)
  •  

    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 18 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2020-10-20 mmuetzel StatusReady For Test Fixed
        Open/ClosedOpen Closed
    2020-06-07 pantxo Attached File- Added bug55225-4.patch, #49222
    2020-06-02 pantxo StatusPatch Submitted Ready For Test
    2020-05-27 pantxo Attached File- Added bug55225-2.patch, #49181
        StatusConfirmed Patch Submitted
    2020-05-26 pantxo Attached File- Added tst_print.patch, #49171
        Attached File- Added bug55225.patch, #49172
    2020-05-24 mmuetzel Attached File- Added t1-0zCjk1.ps, #49161
    2019-11-14 nir_krakauer Attached File- Added buildlog1.txt, #47870
    2019-03-12 pantxo StatusFixed Confirmed
        Open/ClosedClosed Open
    2018-12-21 mtmiller StatusReady For Test Fixed
        Open/ClosedOpen Closed
    2018-12-21 pantxo StatusNone Ready For Test
    2018-12-15 haawda Carbon-Copy- Added -email is unavailable-
    2018-12-14 mtmiller Summarybuilding doc figures in .eps format occasionally silently fails building doc figures in .eps or .pdf format occasionally silently fails
    2018-12-14 mtmiller Carbon-CopyRemoved 80942 -

    Back to the top

    Powered by Savane 3.13-f8d8.
    Corresponding source code