The svg generation takes more time from version plantuml.1.2018.9

Question

Hi,

I tested several versions of Plantuml and I noticed that all versions created after 1.2018.8 take considerably more time for generating exactly the same set of svg files (150 files), around 1/3 of the total time.

Answer 1

Are you using preprocessing in your files ? Preprocessor implementation has been somehow reworked so it can have impact.

Few questions :

- Did you have the same generation time shift with PNG ? (this is to check if SVG generation is the real cause)

- Is it possible to get a diagram sample of yours that now takes more time ? It's difficult to solve the issue without example ?

- Could you also launch your diagram generation with -verbose flag (which prints time information) on both 1.2018.7 version and 1.2018.8 version ?

Thanks!

Comments

IMHO this is not restricted to SVG. The general behavior changed and might be connected to multiple file includes (We had this discussion a couple of days ago with respect to !include_once and !include_many).
Here some tests that I did with different plantuml version and a file that consists of two diagrams that include a number of subsequent files.
To me it looks like the update from 10 to 11 did slow down the process by factor 6 or 7:

plantuml.1.2018.08.jar
(8.294 - 977 Mo) 581 Mo - Ok for com.sun.imageio.plugins.png.PNGMetadata
(8.324 - 977 Mo) 581 Mo - Number of image(s): 2

plantuml.1.2018.10.jar
(5.257 - 691 Mo) 174 Mo - Ok for com.sun.imageio.plugins.png.PNGMetadata
(5.292 - 691 Mo) 174 Mo - Number of image(s): 2

plantuml.1.2018.11.jar
(30.078 - 1028 Mo) 786 Mo - Creating image 618x137
(30.088 - 1028 Mo) 774 Mo - Ok for com.sun.imageio.plugins.png.PNGMetadata
(30.117 - 1028 Mo) 774 Mo - Number of image(s): 2

plantuml.1.2018.12.jar
(32.162 - 883 Mo) 591 Mo - Creating image 618x137
(32.170 - 883 Mo) 591 Mo - Ok for com.sun.imageio.plugins.png.PNGMetadata
(32.197 - 883 Mo) 591 Mo - Number of image(s): 2


plantuml.1.2018.13-beta2
(34.995 - 739 Mo) 582 Mo - Creating image 618x137
(35.005 - 739 Mo) 573 Mo - Ok for com.sun.imageio.plugins.png.PNGMetadata
(35.035 - 739 Mo) 573 Mo - Number of image(s): 2

BR,
Michael

---

With PNG generation it seems it is happening exactly the same.
Here is some information about svg generating for only 1 file in different versions. This file includes another one which only contains skinparams.

plantuml.1.2018.7
(0.827 - 47 Mo) 9 Mo - DotString size: 11971
(0.936 - 47 Mo) 8 Mo - Ending process ok
 (1.453 - 47 Mo) 7 Mo - Number of image(s): 1

plantuml.1.2018.8
 (0.905 - 50 Mo) 32 Mo - DotString size: 11971
(1.029 - 50 Mo) 32 Mo - Ending process ok
 (1.544 - 50 Mo) 32 Mo - Number of image(s): 1

plantuml.1.2018.9
 (1.107 - 83 Mo) 24 Mo - DotString size: 11971
(1.216 - 83 Mo) 24 Mo - Ending process ok
 (1.778 - 83 Mo) 68 Mo - Number of image(s): 1

From version 9, the results are very similar. It does not matter whether the diagram is simple or complex.

In the real usage, I generate with Java:
try (ByteArrayOutputStream os = new ByteArrayOutputStream()) {
                source.outputImage(os, new FileFormatOption(FileFormat.SVG));
                String imageContent = os.toString();
                imageSubSequence = imageContent.subSequence(0, imageContent.length());
            }

Regards

---

Some improvements have been done with last beta http://beta.plantuml.net/plantuml.jar
However performances are highly related to input data so it's difficult to know in your case what will be the result. You tell us :-)

---

Hi,
the fix does the job. 1.2018.12 takes  ~23 seconds, the current beta is ~8 seconds.
BR,
Michael

---

Hi,

I still have some difference in the time spent for svg generation between 2 different versions of Plantuml. Check the example below. I tested it with Java 8 and OpenJdk 11 64 bit.

In a very simple puml file the latest version takes are around 200 milliseconds more. This difference increases in case of complex files. With Java 11 it takes even more time no matter which Plantuml version is used.

Version 1.2018.08

(0.000 - 256 Mo) 250 Mo - PlantUML Version 1.2018.08
(0.010 - 256 Mo) 250 Mo - GraphicsEnvironment.isHeadless() false
(0.011 - 256 Mo) 250 Mo - Forcing resource load on OpenJdk
(0.126 - 256 Mo) 246 Mo - Setting current dir: .
(0.127 - 256 Mo) 246 Mo - Setting current dir: C:\Temp\PlantUML
(0.129 - 256 Mo) 246 Mo - Using default charset
(0.138 - 256 Mo) 246 Mo - Setting current dir: C:\Temp\PlantUML
(0.146 - 256 Mo) 246 Mo - Using default charset
(0.148 - 256 Mo) 246 Mo - Using default charset
(0.148 - 256 Mo) 246 Mo - Setting current dir: C:\Temp\PlantUML
(0.168 - 256 Mo) 245 Mo - Setting current dir: C:\Temp\PlantUML
(0.173 - 256 Mo) 244 Mo - Setting current dir: C:\Temp\PlantUML
(0.173 - 256 Mo) 244 Mo - Reading file: test.puml
(0.583 - 256 Mo) 193 Mo - Creating file: C:\Temp\PlantUML\test.svg
(0.789 - 256 Mo) 186 Mo - Starting Graphviz process [C:\graphviz\exe\dot.exe, -Tsvg]
(0.790 - 256 Mo) 186 Mo - DotString size: 1647
(0.921 - 256 Mo) 185 Mo - Ending process ok
(0.921 - 256 Mo) 185 Mo - Ending Graphviz process
(1.026 - 256 Mo) 216 Mo - TransformerFactory=class com.sun.org.apache.xalan.internal.xsltc.trax.TransformerFactoryImpl
(1.031 - 256 Mo) 216 Mo - Transformer=class com.sun.org.apache.xalan.internal.xsltc.trax.TransformerImpl
(1.092 - 256 Mo) 213 Mo - Number of image(s): 1

Version 1.2019.06

(0.000 - 256 Mo) 250 Mo - PlantUML Version 1.2019.06
(0.012 - 256 Mo) 250 Mo - GraphicsEnvironment.isHeadless() false
(0.013 - 256 Mo) 250 Mo - Forcing resource load on OpenJdk
(0.109 - 256 Mo) 247 Mo - Found 1 files
(0.110 - 256 Mo) 247 Mo - Working on C:\Temp\PlantUML\test.puml
(0.132 - 256 Mo) 246 Mo - Setting current dir: .
(0.132 - 256 Mo) 246 Mo - Setting current dir: C:\Temp\PlantUML
(0.136 - 256 Mo) 246 Mo - Using default charset
(0.142 - 256 Mo) 246 Mo - Reading from test.puml
(0.143 - 256 Mo) 246 Mo - Creating AParentFolderRegular C:\Temp\PlantUML
(0.176 - 256 Mo) 245 Mo - ImportedFiles::getAFile nameOrPath = ./included.puml
(0.177 - 256 Mo) 245 Mo - ImportedFiles::getAFile currentDir = AParentFolderRegular::C:\Temp\PlantUML
(0.177 - 256 Mo) 245 Mo - AParentFolderRegular::looking for ./included.puml
(0.179 - 256 Mo) 245 Mo - AParentFolderRegular::dir = C:\Temp\PlantUML
(0.181 - 256 Mo) 245 Mo - AParentFolderRegular::Filecurrent C:\Temp\PlantUML\.\included.puml
(0.185 - 256 Mo) 245 Mo - ImportedFiles::getAFile filecurrent = AFileRegular::C:\Temp\PlantUML\included.puml
(0.186 - 256 Mo) 245 Mo - Using default charset
(0.195 - 256 Mo) 245 Mo - Reading from ./included.puml
(0.197 - 256 Mo) 245 Mo - Using default charset
(0.199 - 256 Mo) 245 Mo - Reading from ./included.puml
(0.201 - 256 Mo) 245 Mo - Getting parent of AFileRegular::C:\Temp\PlantUML\included.puml
(0.202 - 256 Mo) 245 Mo - Creating AParentFolderRegular C:\Temp\PlantUML
(0.212 - 256 Mo) 245 Mo - -->The parent is AParentFolderRegular::C:\Temp\PlantUML
(0.214 - 256 Mo) 245 Mo - Creating AParentFolderRegular C:\Temp\PlantUML
(0.235 - 256 Mo) 243 Mo - Reading file: test.puml
(0.784 - 355 Mo) 309 Mo - Creating file: C:\Temp\PlantUML\test.svg
(0.965 - 355 Mo) 303 Mo - Starting Graphviz process [C:\graphviz\exe\dot.exe, -Tsvg]
(0.967 - 355 Mo) 303 Mo - DotString size: 1647
(1.086 - 355 Mo) 301 Mo - Ending process ok
(1.087 - 355 Mo) 301 Mo - Ending Graphviz process
(1.183 - 355 Mo) 297 Mo - TransformerFactory=class com.sun.org.apache.xalan.internal.xsltc.trax.TransformerFactoryImpl
(1.187 - 355 Mo) 297 Mo - Transformer=class com.sun.org.apache.xalan.internal.xsltc.trax.TransformerImpl
(1.248 - 355 Mo) 295 Mo - Number of image(s): 1

test.puml:

@startuml
    !include ./included.puml
    title Test
    Start -[#00AA00]-> "Element 1" as element_1 <<Activity>>
    element_1 -[#00AA00]-> "Element 2" as element_2 <<Activity>>
    element_2 -[#00AA00]-> "Element 3" as element_3 <<Activity>>
    element_3 -[#00AA00]-> "Element 4" as element_4 <<Activity>>
    element_4 -[#00AA00]-> "Element 5" as element_5 <<Activity>>
    element_5 -[#00AA00]-> "Element 6" as element_6 <<Activity>>
    element_6 -[#00AA00]-> "Element 7" as element_7 <<Activity>>
    element_7 -[#00AA00]-> "Element 8" as element_8 <<Activity>>
    element_8 -[#00AA00]-> "Element 9" as element_9 <<Activity>>
    element_9 -[#00AA00]-> "Element 10" as element_10 <<Activity>>
@enduml

included.puml:

@startuml
skinparam Note {
        BorderColor Gray
        BackgroundColor White
        FontColor Gray
        FontName Arial
        FontSize 12
        FontStyle Bold
        BorderThickness 1
    }
    skinparam Package {
        BorderColor Black
        BackgroundColor #F7F7F7
        FontColor Black
        FontName Arial
        FontSize 12
        FontStyle Normal
        BorderThickness 1
    }
    skinparam Activity {
        ArrowColor Gray
        ArrowFontName Arial
        ArrowFontColor Gray
        ArrowFontSize 12
        ArrowFontStyle Normal
        ArrowHeaderColor Red
        BorderColor #00AA00
        BackgroundColor White
        FontColor Black
        FontName Arial
        FontSize 12
        FontStyle Normal
    }

@enduml

Regards

---

Thanks for your example. We've tested it using JProfiler but we did not seen anything obvious. On our config, your example run in 700 ms, which is too quick to do some investigations. We are using Oracle JVM and not OpenJDK.

It may help if you have a larger diagram showing the performance issue. If you don't want to share your diagram, you can use the -cypher option that transform a valid diagram info another valid diagram, but with random and meaningless text. The best option would be a sequence diagram (since it does not use GraphViz).

You can also send such cyphered diagram by email at plantuml@gmail.com

Thanks!

---

Actually, it is an activity diagram. I will send you it by email.

By the way, it seems that if there are <img> tags then it takes clearly more time. I have noticed it after testing the cyphered one where img tags were also cyphered. So I fixed this and I compared generation times.

Even if there is a small difference (around 200 milliseconds), it has an impact when generating hundreds of diagrams.

Thanks.