EtheaDev / SVGIconImageList

Three engines to render SVG (Delphi Image32, Skia4Delphi, Direct2D wrapper) and four components to simplify use of SVG images (resize, fixedcolor, grayscale...)
Apache License 2.0
327 stars 96 forks source link

Tips for speeding up loading/form initialization? #197

Closed luebbe closed 3 years ago

luebbe commented 3 years ago

Hi folks,

while porting an application to SVGIconImageList, I noticed that the intial loading time of the application doubles when SVGIconImageList is used instead of loading the imagelists from a bmp. The application has four imagelists (each has ~150 icons) with different colorations. These are on a data module which loads the images when the application is started. This is the first step in the dpr after starting the logging. In case of BMP it loads the four imagelists from a BMP into a TImageList each. In case of SVG it loads the SVGs and does some recoloring before adding them to the four TSVGIconImageCollections and assigning them to a TVirtualImageList each.

The timings in the table below are taken from logging. The application was started twice each time in order to reduce any windows caching effect. Time is in milliseconds.

Step Action BMP Img32 TSVG
0 Load images start 1300 1200 1300
1 Load images done 1327 1800 2100
2 Create first form 1800 5300 5300
3 Show first form 6800 14300 15700

Give or take 100ms, the images are all loaded at the same time. Since there is some recoloring done, I can understand that the SVG factories need longer for step 1. But what happens between step 1 and 2? Are the TVirtualImageLists busy creating icons before the first TForm.Create is run? Also the effect seems to add up over time. It looks like each form that is using the TVirtualImageLists from the data module is taking longer to initialize than before. In the end, when all forms are created and the first form is shown, the delay has added up to more than 7 seconds, which is twice as much as the time needed for the "load BMP" version.

Later, when I switch between light and dark design, which means that the dark/light image collections are assigned to the virtual image lists, there is no difference between the TImageList and TVirtualImageList implementation. Both need around 600ms from the start of the action to the moment when the form is shown again.

Do you have any idea where the time is spent when the forms are created? Do you have any hints on how I could speed up the process?

carloBarazzetta commented 3 years ago

The best scenario is to put only ImageCollections in the datamodule, not ImageLists: if you put an imagelist in the datamodule you will not be able to share it on forms with different DPI, so you should have a VirtualImageList on each form that contains only the icons necessary for that form. If you need images with "different colorations" use four ImageCollection: at startup you can load the svg in the collection and make the different colorations (I suppose changing svg text of images or applying fixedcolor to the ImageCollection): this operation don't generate any bitmap in memory! Only when opening a form with a VirtualImageList that requests the bitmaps in a specific size they are rendered by the ImageCollection and you can put different VirtualImageList with different sizes also in the same Form so you can have for example a 32x32 icons on toolbutton and 24x24 icons on buttons, this is more flexible instead of using always the same imagelist (with the same size) placed into the main datamodule... I hope I understand the problem and have given you some good suggestions.

luebbe commented 3 years ago

Hi Carlo,

thanks a lot for your reply. You have given me some good suggestions indeed.

The best scenario is to put only ImageCollections in the datamodule, not ImageLists: if you put an imagelist in the datamodule you will not be able to share it on forms with different DPI, so you should have a VirtualImageList on each form that contains only the icons necessary for that form.

That's what I'm planning to do. For now I'm still sharing the four imagelists between all forms. Reason at the end of my reply.

If you need images with "different colorations" use four ImageCollection: at startup you can load the svg in the collection and make the different colorations (I suppose changing svg text of images or applying fixedcolor to the ImageCollection): this operation don't generate any bitmap in memory!

That's exactly what I'm doing.

Only when opening a form with a VirtualImageList that requests the bitmaps in a specific size they are rendered by the ImageCollection and you can put different VirtualImageList with different sizes also in the same Form so you can have for example a 32x32 icons on toolbutton and 24x24 icons on buttons, this is more flexible instead of using always the same imagelist (with the same size) placed into the main datamodule...

Basically that's what I'm doing. The four imagelists on the datamodule have two different sizes and enabled/disabled. Enabled/disabled, because some components want one list for each and others want one list, which contains enabled+disabled icons.

The problem with the individual imagelists per form is that our image indexes are constants which are generated from the alphabetically sorted svg names. In each form I can say actClose.ImageIndex := cImgClose, no matter which form it is. If I switch to individual image lists per form, e.g. one with five, the other with ten images, actClose.ImageIndex may be one in the first form and five in the second. This means that our current approach wouldn't work anymore and I'd have to find a new way to ensure consistent icon usage througout the application.

But I still don't understand why creating the forms takes so much longer. I have four TVirtualImageLists instead of four TImageLists and they are assigned to each form's action lists, toolbars etc. during FormCreate. That code hasn't changed.

carloBarazzetta commented 3 years ago

I've notice that the the VirtualImageList request the same bitmap from SVGIconImageCollection two times: into TVirtualImageList.UpdateImageList (after loading ImageList from dfm) and from NotifyGlobalLoading of datamodule. So I've tried to add a simple bitmap caching method into TSVGIconItem.GetBitmap. Please try the attached unit that includes this optimization and give me a feed-back if your speed increase... SVGIconItems.zip

luebbe commented 3 years ago

Hi Carlo, thanks for the optimization. It results in a small improvement in loading speed. Overall it's about a second faster from step 0 to step 3

So the table now looks like this: Img32+ is the version with the optimization.

Step Action BMP Img32 Img32+
0 Load images start 1300 1200 1300
1 Load images done 1327 1800 1800
2 Create first form 1800 5300 5800
3 Show first form 6800 14300 13100

Again three runs with average values. Note that from step 1 to step 2 it now needs half a second more than before. It gains a bit in the long run while the forms are created, but still needs almost twice as long as the plain .bmp version.

carloBarazzetta commented 3 years ago

It's not the result that I'm expected... Can you debug the process to render the bitmap from SVG to see if this method is called too many times in your scenario? Please put a breakpoint into TImage32SVG.PaintTo: this is the unique method that "build" the bitmap using Image32 library: with the last optimization in a simple demo with 3 icons this mehod is called only 3 times. If you notice that this method is called too many times check the callstack to see why... If you have 150 icons x 4 and this method is called more than 600 times we must investigate the problem... if it was called only 600 time, the poor performance are affected by the time needed by Image32 to parse SVG an draw the bitmap. If you can you send me a test demo extracted from your project I can do more tests. Bye

luebbe commented 3 years ago

Ok, I added some logging to a reduced demo application, which I use for VCL style tests. It unfortunately still contains too much internal stuff and depends on TMS components.

for the logging in TImage32SVG I added a global and a local counter, which I increment on each call to PaintTo.

procedure TImage32SVG.PaintTo(DC: HDC; R: TRectF; KeepAspectRatio: Boolean);
var
  dx,dy: double;
  color: TColor32;
begin
  inc(fCount);
  inc(g_paintcount);
  g_Logger.Info('TImage32SVG.PaintTo ' + IntToStr(fCount) + ' ' + InttoStr(g_paintcount));

So in the table below the output TImage32SVG.PaintTo 2 978 means: "The current icons is painted for the second time and it PaintTo is called for the 978th time over all"

reduced log with comments

The demo application only has four forms, so the delay which is obvious when our main application is started, isn't visible here. I don't see any unexpected behaviour in this log apart from the last round of calls to PaintTo near the end. I'll double check tomorrow with our main application and more logging, but for today I'm running out of time.

Timestamp Log Cat Info Comment
14:38:04:115 INF GEN Windows 10 (Version 10.0, Build 19041, 64-Bit-Edition)
14:38:04:115 INF GEN Current Windows codepage: 1252 (ANSI - Lateinisch I)
14:38:04:188 --> GEN LoadImages
14:38:04:188 INF GEN Loaded 151 icons 2 logos Note: although there are only 151 icons loaded, 11 special colorized icons are created from grayscale icons so the 162 difference observed below is correct.
14:38:04:188 INF GEN Load dark image collection
14:38:04:188 INF GEN Load disabled
14:38:04:300 INF GEN Load enabled
14:38:04:400 INF GEN Load disabled toolbar
14:38:04:616 INF GEN Load enabled toolbar
14:38:04:848 INF GEN Assign image collections (Button & Toolbar)
14:38:04:848 INF GEN Assign dark image collection
14:38:04:848 INF GEN - enabled generic 1..326 makes sense here, because the disabled icons are appended to the generic list.
14:38:04:854 INF GEN TImage32SVG.PaintTo 1 1
...
14:38:04:970 INF GEN TImage32SVG.PaintTo 1 326
14:38:04:970 INF GEN - disabled generic contains only the disabled icons, which is why they are painted a second time
14:38:04:970 INF GEN TImage32SVG.PaintTo 2 327
...
14:38:05:032 INF GEN TImage32SVG.PaintTo 2 489
14:38:05:032 INF GEN - enabled toolbar contains only the enabled icons
14:38:05:032 INF GEN TImage32SVG.PaintTo 1 490
...
14:38:05:086 INF GEN TImage32SVG.PaintTo 1 652
14:38:05:086 INF GEN - disabled toolbar contains only the disabled icons
14:38:05:086 INF GEN TImage32SVG.PaintTo 1 653
...
14:38:05:155 INF GEN TImage32SVG.PaintTo 1 815
14:38:05:155 INF GEN Assign image collections (Menu)
14:38:05:155 INF GEN Assign dark image collection
14:38:05:155 INF GEN - enabled Toolbar enabled also contains enabled and disabled icons
14:38:05:155 INF GEN TImage32SVG.PaintTo 2 816 enabled painted a second time
...
14:38:05:202 INF GEN TImage32SVG.PaintTo 2 978
14:38:05:202 INF GEN TImage32SVG.PaintTo 3 979 disabled painted a third time
...
14:38:05:255 INF GEN TImage32SVG.PaintTo 3 1141
14:38:05:255 INF GEN - disabled Toolbar disabled only contains disabled icons
14:38:05:255 INF GEN TImage32SVG.PaintTo 4 1142 disabled painted a fourth time
...
14:38:05:302 INF GEN TImage32SVG.PaintTo 4 1304
14:38:05:318 INF GEN - enabled toolbar
14:38:05:318 INF GEN - disabled toolbar
14:38:05:318 <-- GEN LoadImages
14:38:05:349 INF GEN TImage32SVG.PaintTo 1 1305 Probably painting the logo(s) on the splash screen
14:38:05:349 INF GEN TImage32SVG.PaintTo 1 1306
14:38:05:504 INF GEN TImage32SVG.PaintTo 2 1307
14:38:05:618 DBG GEN Create Begin dpnl=41 tbr=39 btn h=35 w=35 iml h=33 w=33 The main form is created here
14:38:05:618 INF GEN Main.ImageList - START Assignment of the data module image lists to the main form's image lists
14:38:05:618 INF GEN Main.ImageList - END
14:38:05:656 DBG GEN Create End dpnl=41 tbr=39 btn h=35 w=35 iml h=33 w=33
14:38:05:872 INF GEN TfrmDemo.ImageList - START Assignment of the data module image lists to another form's image lists
14:38:05:872 INF GEN TfrmDemo.ImageList - END
14:38:05:904 INF GEN FM: Create During creation of a third form
14:38:07:758 DBG GEN Show dpnl=41 tbr=39 btn h=35 w=35 iml h=33 w=33 The main form is shown
14:38:07:779 DBG GEN Resize dpnl=41 tbr=39 btn h=35 w=35 iml h=33 w=33 Some resize events on the main form
14:38:07:794 DBG GEN Resize dpnl=41 tbr=39 btn h=35 w=35 iml h=33 w=33
14:38:07:934 DBG GEN Resize dpnl=41 tbr=39 btn h=35 w=35 iml h=33 w=33
14:38:08:144 INF GEN TImage32SVG.PaintTo 3 1308 No idea yet what triggers these PaintTo events
...
14:38:08:195 INF GEN TImage32SVG.PaintTo 3 1470
14:38:08:195 INF GEN TImage32SVG.PaintTo 5 1471
...
14:38:08:311 INF GEN TImage32SVG.PaintTo 5 1633
pyscripter commented 3 years ago

Are you using the patch from https://quality.embarcadero.com/browse/RSP-30931?

luebbe commented 3 years ago

@pyscripter not yet, but I'll give it a go.

It looks like this is a side effect of gnu gettext. Following @carloBarazzetta's suggestion, I set a breakpoint on PaintTo in our main application. This is called a zillion times from TSVGIconItems.Update and this in turn is triggered by TGnuGettextInstance.TranslateComponent.

Have a look at the call stack.

grafik

This happens for each of "a hundred" forms. I think I have to find a way to exclude the SVG Icon collections from gettext. This is also the reason why the demo app didn't behave badly. It doesn't use gettext.

Gettext tries to translate string properties. In my case it had a match with "IconName". This makes me wonder if the image collection/icon really has to be updated/repainted, when the icon's name changes?!?

luebbe commented 3 years ago

Yes, that was it I added:

initialization
TP_GlobalIgnoreClass(TSVGIconImageCollection);

to the initialization section of my data module and now the loading time for the application is down to seven seconds again. Sometimes ten, but that doesn't seem to have anything to do with the SVGIconImageCollection.

So if I update my table again with the times taken after excluding TSVGIconImageCollection from translation:

Step Action BMP Img32 Img32+
0 Load images start 1300 1200 1300
1 Load images done 1327 1800 1800
2 Create first form 1800 2100 2200
3 Show first form 6800 7300 7500

@carloBarazzetta your optimization with the cache doesn't seem to have a measurable impact. The time needed to load and populate the image collections is always around 600ms. The timing differences between cache and non-cache version, fall into measurement tolerance IMHO.

carloBarazzetta commented 3 years ago

I'm glad you found the problem and the solution, so my "optimization" is not needed... I suppose that the icon is repainted if the name of the icon changed into this method: procedure TSVGIconItem.SetIconName(const Value: string); begin if FIconName <> Value then begin FIconName := Value; Changed(False); end; end; because from Delphi 10.4 you can "point" to an image by name, not only by index.

I'm closing this issue.

luebbe commented 3 years ago

Exactly. That's the procedure which triggers the Changed event, which calls Update for the entire collection. So there probably is no way to avoid repainting the icon, when it's name is updated? The side effect of using Gettext is nasty though. Is there a "known issues" section in the Wiki? If not, I'll add a three liner explaining the problem and the solution.

carloBarazzetta commented 3 years ago

@luebbe I've added a new page into wiki to explain how to use those components: https://github.com/EtheaDev/SVGIconImageList/wiki/Virtual-image-collection At the end I've added a section regarding use of Icon Names. Edit this page and explain the problem using Get-It (...and please fix also the text of my "poor" english). Thanks.

luebbe commented 3 years ago

@carloBarazzetta since I can't add or edit Wiki pages, I started to write a short "Known Issues.md" and wanted to attach it to a ticket. Maybe I need extra permissions to edit Wiki pages?

carloBarazzetta commented 3 years ago

I sent you an invitation to collaborate directly on the project.

luebbe commented 3 years ago

Now I can edit. I'll add the info later. Thank you!