Running ScalaDoc with -diagram fails on OS X 10.9 (Mavericks)

[scabug]

When running scaladoc with -diagrams on OS X 10.9 there are warnings printed to stderr of the dot process, and this is interpreted as a failure even though the process completes and produces the SVG.

**********************************************************************
The graphviz dot diagram tool has malfunctioned and will be restarted.

The following is the log of the failure:
  DOT <error console>: 2013-11-05 14:30:26.674 dot[36780:507] CoreText performance note: Client called CTFontCreateWithName() using name "Arial" and got font with PostScript name "ArialMT". For best performance, only use PostScript names when calling this API.
  DOT <error console>: 2013-11-05 14:30:26.675 dot[36780:507] CoreText performance note: Set a breakpoint on CTFontLogSuboptimalRequest to debug.
  DOT <error console>: 2013-11-05 14:30:26.700 dot[36780:507] CoreText performance note: Client called CTFontCreateWithName() using name "Arial" and got font with PostScript name "ArialMT". For best performance, only use PostScript names when calling this API.
  Error thread in akka: Exception: java.lang.ThreadDeath
  Input thread in akka: Exception: java.lang.InterruptedException

  Cleanup: Last template: akka
  Cleanup: Last dot input:
    digraph G {
    compound="true";
    rankdir="TB";
    node [margin="0.08,0.01", fontsize="10.00", style="filled", height="0.0", penwidth="1", shape="rectangle", width="0.0", fontname="Arial"];
    edge [arrowsize="0.5", fontcolor="#aaaaaa", fontsize="10.00", color="#d4d4d4", fontname="Arial"];

    node0 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/bjorn/Source/typesafe/akka/master-3/akka-actor/target/api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">ConfigurationException </TD></TR></TABLE>>,fontcolor="#ffffff", URL="ConfigurationException.html#inheritance-diagram", color="#115F3B", id="class|graph1_0", fillcolor="#0A955B", tooltip="akka.ConfigurationException"];
    node1 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/bjorn/Source/typesafe/akka/master-3/akka-actor/target/api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">AkkaException </TD></TR></TABLE>>,fontcolor="#ffffff", URL="AkkaException.html#inheritance-diagram", color="#115F3B", id="class|graph1_1", fillcolor="#0A955B", tooltip="akka.AkkaException"];
    node1 -> node0 [id="inheritance|graph1_1_0", tooltip="ConfigurationException is a subtype of AkkaException", dir="back", arrowtail="empty"];
    }

  Cleanup: Dot path: dot
  Cleanup: Dot exit code: 143
**********************************************************************
Graphviz will be restarted...

[scabug]

Imported From: https://issues.scala-lang.org/browse/SI-7950?orig=1 Reporter: Björn Antonsson (bjorn.antonsson)

[scabug]

@VladUreche said: Looks like dot doesn't like the Arial font, but wants ArialMT. Maybe someone who has a Mac box can try changing these lines in scaladoc, replacing Arial by ArialMT: https://github.com/scala/scala/blob/master/src/scaladoc/scala/tools/nsc/doc/html/page/diagram/DotDiagramGenerator.scala#L448 https://github.com/scala/scala/blob/master/src/scaladoc/scala/tools/nsc/doc/html/page/diagram/DotDiagramGenerator.scala#L457

[scabug]

Markus Klink (justjoheinz) said: I have the same error on Mac OS X. I can't compile scaladoc right now, however I took the .dot output from the -diagrams-debug option and used dot manually to produce an output file and that works. Using this step I get the same warning as documented above about "Arial". dot also returns "0" giving a hint that it did not produce an error. Maybe scaladoc thinks that an error occured because dot is writing to stdout /stderr which is not expected?

[scabug]

Markus Klink (justjoheinz) said: One more observation - if I rename Arial to ArialMT in the dot file I get a silent output, instead of the error messages mentioned above.

[scabug]

Björn Antonsson (bjorn.antonsson) said: Yes, as I said in the ticket, the scaladoc code interprets any output to stderr as a failure (maybe a bit to aggressive)

In the meantime you can place this as your dot command first in the path to filter out the warnings.

#!/bin/bash
/usr/local/bin/dot "$@" 2> >( grep -v "CoreText performance note:" >&2 )

[scabug]

@VladUreche said: Björn, very nice workaround, thanks a lot! I'm not sure how to fix this issue -- normally one would use the exit code to determine if the execution was correct, but for performance reasons we don't let dot shut down but batch hundreds of diagrams in a single process execution. So the only solution I see is ignoring lines containing "CoreText performance note:", which is an ugly hard-coding.

[scabug]

@Blaisorblade said: Does dot generate a well-formed SVG content in case of serious errors? If not, could one use that as an alternative criterion? Stderr should still be logger for debugging somewhere — for instance in the output folder (by default), or a configurable location (if specified).

Now, since Arial's "Postscript" name seems to ArialMT, I wonder if the font name could be changed to ArialMT for all platforms. Could somebody with a Windows/Linux machine try the change? (I might be able to test it inside some VM, at least for Linux).

[scabug]

@VladUreche said (edited on Feb 19, 2014 11:00:46 AM UTC): Paolo, if dot encounters a serious error, it won't output anything at all, so waiting for the svg output will make scaladoc hang. This is the reason I consider the process failed on the first stderr output: following that, it's likely that expecting the svg is useless. Yet, in many cases, dot won't exit with an error code but just continue waiting for the next diagram, so I can't rely on the process exiting either. I'd say I just don't have the signals necessary to coordinate with dot well enough.

[scabug]

@Blaisorblade said (edited on Feb 19, 2014 3:14:44 PM UTC):

I'd say I just don't have the signals necessary to coordinate with dot well enough. I see a way around the cases you described and the ones I've met myself, though it's not extremely robust. But I agree that this is all rather crazy.

Unlike you wrote, currently Scaladoc will not hang. Instead, it will time out. For the scenarios discussed, giving up when there's an error is only an optimization to fail faster. Taking longer to fail when there's an actual setup problem seems acceptable to me, though of course it's a judgment call.

So, it seems that scaladoc could just store the standard error, display it if there's a timeout and only log it otherwise.

This might also be compatible with the other scenario I observed — spurious failures from dot. In my case, I observe (with GraphViz 2.34.0 and 2.36.0) the memory corruptions below inside GraphViz (not due to scaladoc). If graphviz produce no output or recognizably garbled output, then ignoring the standard error would be OK. However, since in this case dot just crashes and exits, it's still easy to detect something's wrong without looking at the standard error.

What I saw with diagrams-debug was pretty insane. EDIT: the below just documents the heap corruptions, feel free to ignore it.

[info] Test Scala API documentation to /Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api...
model contains 120 documentable templates

**********************************************************************
The graphviz dot diagram tool has malfunctioned and will be restarted.

The following is the log of the failure:
  DOT <error console>: Warning: Unable to reclaim box space in spline routing for edge "node0" -> "node4". Something is probably seriously wrong.
  DOT <error console>: dot(18359,0x7fff78102310) malloc: *** error for object 0x7f861b604f30: pointer being freed was not allocated
  DOT <error console>: *** set a breakpoint in malloc_error_break to debug
  DOT <error console>: /Users/pgiarrusso/bin/dot: line 2: 18359 Abort trap: 6           /usr/local/bin/dot "$@" 2> >( grep -v "CoreText performance note:" >&2 )

  Cleanup: Last template: ilc.language.bacchus.BacchusEvaluationSuite
  Cleanup: Last dot input:
    digraph G {
    compound="true";
    rankdir="TB";
    node [margin="0.08,0.01", fontsize="10.00", style="filled", height="0.0", penwidth="1", shape="rectangle", width="0.0", fontname="Arial"];
    edge [arrowsize="0.5", fontcolor="#aaaaaa", fontsize="10.00", color="#d4d4d4", fontname="Arial"];
    subgraph clusterAll {
    style="invis"
    subgraph clusterOutgoing {
    style="invis"
    node5 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">org.scalautils.TripleEquals.Equalizer[BacchusEvaluationSuite] </TD></TR></TABLE>>,fontcolor="#7d7d7d", color="#ababab", id="implicit-outgoing class|graph14_5", fillcolor="#e1e1e1", tooltip="ilc.language.bacchus.BacchusEvaluationSuite can be implicitly converted to org.scalautils.TripleEquals.Equalizer[BacchusEvaluationSuite] by the implicit method convertToEqualizer in trait org.scalautils.TripleEquals"];
    node4 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">org.scalatest.Assertions.Equalizer[BacchusEvaluationSuite] </TD></TR></TABLE>>,fontcolor="#7d7d7d", color="#ababab", id="implicit-outgoing class|graph14_4", fillcolor="#e1e1e1", tooltip="ilc.language.bacchus.BacchusEvaluationSuite can be implicitly converted to org.scalatest.Assertions.Equalizer[BacchusEvaluationSuite] by the implicit method convertToEqualizer in trait org.scalautils.TripleEquals"];
    node4 -> node5 [constraint="false", style="invis", minlen="0.0"];
    }
    subgraph clusterThis {
    style="invis"
    node0 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">BacchusEvaluationSuite </TD></TR></TABLE>>,fontcolor="#ffffff", URL="#inheritance-diagram", color="#115F3B", id="this class|graph14_0", fillcolor="#0A955B", tooltip="ilc.language.bacchus.BacchusEvaluationSuite (this class)"];
    }

    node0 -> node4 [id="implicit-outgoing|0_4", tooltip="BacchusEvaluationSuite can be implicitly converted to org.scalatest.Assertions.Equalizer[BacchusEvaluationSuite], org.scalautils.TripleEquals.Equalizer[BacchusEvaluationSuite]", constraint="false", minlen="2", ltail="clusterThis", lhead="clusterOutgoing", label="implicitly"];
    }
    node1 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">FunSuite </TD></TR></TABLE>>,fontcolor="#ffffff", color="#115F3B", id="class|graph14_1", fillcolor="#0A955B", tooltip="org.scalatest.FunSuite"];
    node2 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/trait_diagram.png" /></TD><TD VALIGN="MIDDLE">Subjects </TD></TR></TABLE>>,fontcolor="#ffffff", URL="Subjects.html#inheritance-diagram", color="#37657D", id="trait|graph14_2", fillcolor="#498AAD", tooltip="ilc.language.bacchus.Subjects"];
    node3 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/trait_diagram.png" /></TD><TD VALIGN="MIDDLE">Evaluation </TD></TR></TABLE>>,fontcolor="#ffffff", color="#37657D", id="trait|graph14_3", fillcolor="#498AAD", tooltip="ilc.language.bacchus.Evaluation"];
    node1 -> node0 [id="inheritance|graph14_1_0", tooltip="BacchusEvaluationSuite is a subtype of FunSuite", dir="back", arrowtail="empty"];
    node2 -> node0 [id="inheritance|graph14_2_0", tooltip="BacchusEvaluationSuite is a subtype of Subjects", dir="back", arrowtail="empty"];
    node3 -> node0 [id="inheritance|graph14_3_0", tooltip="BacchusEvaluationSuite is a subtype of Evaluation", dir="back", arrowtail="empty"];
    }

  Cleanup: Dot path: dot
  Cleanup: Dot exit code: 134
**********************************************************************
Graphviz will be restarted...

**********************************************************************
The graphviz dot diagram tool has malfunctioned and will be restarted.

The following is the log of the failure:
  DOT <error console>: Warning: Unable to reclaim box space in spline routing for edge "node0" -> "node4". Something is probably seriously wrong.
  DOT <error console>: dot(18364,0x7fff78102310) malloc: *** error for object 0x7fcd70e59d30: pointer being freed was not allocated
  DOT <error console>: *** set a breakpoint in malloc_error_break to debug
  DOT <error console>: /Users/pgiarrusso/bin/dot: line 2: 18364 Abort trap: 6           /usr/local/bin/dot "$@" 2> >( grep -v "CoreText performance note:" >&2 )

  Cleanup: Last template: ilc.feature.base.TermBuilderSuite
  Cleanup: Last dot input:
    digraph G {
    compound="true";
    rankdir="TB";
    node [margin="0.08,0.01", fontsize="10.00", style="filled", height="0.0", penwidth="1", shape="rectangle", width="0.0", fontname="Arial"];
    edge [arrowsize="0.5", fontcolor="#aaaaaa", fontsize="10.00", color="#d4d4d4", fontname="Arial"];
    subgraph clusterAll {
    style="invis"
    subgraph clusterOutgoing {
    style="invis"
    node5 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">org.scalautils.TripleEquals.Equalizer[TermBuilderSuite] </TD></TR></TABLE>>,fontcolor="#7d7d7d", color="#ababab", id="implicit-outgoing class|graph31_5", fillcolor="#e1e1e1", tooltip="ilc.feature.base.TermBuilderSuite can be implicitly converted to org.scalautils.TripleEquals.Equalizer[TermBuilderSuite] by the implicit method convertToEqualizer in trait org.scalautils.TripleEquals"];
    node4 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">org.scalatest.Assertions.Equalizer[TermBuilderSuite] </TD></TR></TABLE>>,fontcolor="#7d7d7d", color="#ababab", id="implicit-outgoing class|graph31_4", fillcolor="#e1e1e1", tooltip="ilc.feature.base.TermBuilderSuite can be implicitly converted to org.scalatest.Assertions.Equalizer[TermBuilderSuite] by the implicit method convertToEqualizer in trait org.scalautils.TripleEquals"];
    node4 -> node5 [constraint="false", style="invis", minlen="0.0"];
    }
    subgraph clusterThis {
    style="invis"
    node0 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">TermBuilderSuite </TD></TR></TABLE>>,fontcolor="#ffffff", URL="#inheritance-diagram", color="#115F3B", id="this class|graph31_0", fillcolor="#0A955B", tooltip="ilc.feature.base.TermBuilderSuite (this class)"];
    }

    node0 -> node4 [id="implicit-outgoing|0_4", tooltip="TermBuilderSuite can be implicitly converted to org.scalatest.Assertions.Equalizer[TermBuilderSuite], org.scalautils.TripleEquals.Equalizer[TermBuilderSuite]", constraint="false", minlen="2", ltail="clusterThis", lhead="clusterOutgoing", label="implicitly"];
    }
    node1 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/class_diagram.png" /></TD><TD VALIGN="MIDDLE">FunSuite </TD></TR></TABLE>>,fontcolor="#ffffff", color="#115F3B", id="class|graph31_1", fillcolor="#0A955B", tooltip="org.scalatest.FunSuite"];
    node2 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/trait_diagram.png" /></TD><TD VALIGN="MIDDLE">Syntax </TD></TR></TABLE>>,fontcolor="#ffffff", color="#37657D", id="trait|graph31_2", fillcolor="#498AAD", tooltip="ilc.feature.base.Syntax"];
    node3 [label=<<TABLE BORDER="0" CELLBORDER="0"><TR><TD><IMG SCALE="TRUE" SRC="/Users/pgiarrusso/Documents/Research/Sorgenti/ilc/scala-prototype/target/scala-2.10/test-api/lib/trait_diagram.png" /></TD><TD VALIGN="MIDDLE">functions.Syntax </TD></TR></TABLE>>,fontcolor="#ffffff", color="#37657D", id="trait|graph31_3", fillcolor="#498AAD", tooltip="ilc.feature.functions.Syntax"];
    node1 -> node0 [id="inheritance|graph31_1_0", tooltip="TermBuilderSuite is a subtype of FunSuite", dir="back", arrowtail="empty"];
    node2 -> node0 [id="inheritance|graph31_2_0", tooltip="TermBuilderSuite is a subtype of Syntax", dir="back", arrowtail="empty"];
    node3 -> node0 [id="inheritance|graph31_3_0", tooltip="TermBuilderSuite is a subtype of functions.Syntax", dir="back", arrowtail="empty"];
    }

  Cleanup: Dot path: dot
  Cleanup: Dot exit code: 134
**********************************************************************
Graphviz will be restarted...

Diagram generation running time breakdown:

  diagrams model filtering
  ========================
    count:        480 items
    total time:   1 ms
    average time: 0 ms
    maximum time: 1 ms

  diagrams model generation
  =========================
    count:        480 items
    total time:   98 ms
    average time: 0 ms
    maximum time: 6 ms

  dot diagram generation
  ======================
    count:        136 items
    total time:   84 ms
    average time: 0 ms
    maximum time: 18 ms

  dot process runnning
  ====================
    count:        136 items
    total time:   3393 ms
    average time: 24 ms
    maximum time: 944 ms

  svg processing
  ==============
    count:        136 items
    total time:   581 ms
    average time: 4 ms
    maximum time: 67 ms

  Broken images: 786
  Fixed images: 0

[info] Test Scala API documentation successful.

[If I were on Linux, I could just run valgrind around graphviz and send a bug report to graphviz people — assuming the memory corruption is not OS X specific. But I don't have time for that.]

[scabug]

@VladUreche said (edited on Feb 19, 2014 7:10:15 PM UTC): bq. This might also be compatible with the other scenario I observed — spurious failures from dot. In my case, I observe (with GraphViz 2.34.0 and 2.36.0) the memory corruptions below inside GraphViz (not due to scaladoc). bq. If graphviz produce no output or recognizably garbled output, then ignoring the standard error would be OK. However, since in this case dot just crashes and exits, it's still easy to detect something's wrong without looking at the standard error.

I tried that too -- the problem is that some of the build machines are quite slow, and package diagrams can easily take 10s to generate. Setting a timeout below 10s will prevent diagrams for large packages (arguably the most important ones). On the other hand, waiting 10 times 10 seconds (before scaladoc gives up generating diagrams) is too much. Tbh, knowing how much time went into fine-tuning this interaction with dot, I'd rather just live with the issue.

[sorry for the inital post, pressed the wrong button]

[scabug]

@VladUreche said: bq. What I saw with diagrams-debug was pretty insane.

Yes, dot corrupts its heap after a number of diagrams on all platforms. I remember reporting a bug on their tracker, but it was quite hard to replicate. No idea if they fixed it in the meantime.

[scabug]

@refried said: This is still a problem, using graphviz 2.38.0. Maybe the font name could be changed based on platform, in the input?

[scabug]

@refried said: Ignore my previous comment. We have to accept the fact that dot issues both warnings and errors. If you don't want to check the return code, then you have to filter out the warnings. Vlad points out that this is an ugly solution, but imo Elegant Solution > Ugly Solution > No Solution

How about: optimistically try in batch mode like it's done now; if there's stderr output, fall back to individual invocations, where you can check the return code.

[scabug]

@refried said: Especially if dot corrupts itself after a number of diagrams: just don't do individual diagrams. Correctness > Performance

[scabug]

@Blaisorblade said: bq. Maybe the font name could be changed based on platform, in the input?

I agree that would be an improvement. Yes, that's also a bit hacky, but less so than filtering the output, and given the alternatives I'd just go for it.

I also proposed changing on all platforms, pending testing:

bq. Now, since Arial's "Postscript" name seems to ArialMT, I wonder if the font name could be changed to ArialMT for all platforms. Could somebody with a Windows/Linux machine try the change?

But I guess either change should technically work.

Arya, I've seen your other comments, but currently this is the only harmless warning.

[scabug]

@Blaisorblade said (edited on Aug 13, 2014 1:23:43 PM UTC): A proper solution would be possible but require adding features to dot to make it easier to control:

bq. I'd say I just don't have the signals necessary to coordinate with dot well enough.

So I don't recommend waiting for that, but it would be cool if somebody competent could open a dot issue. For now picking a working font will have to do.

[SethTisue]

can someone confirm if this ticket should remain open...?