Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
6 Oct 22, 18:05
in response to: davidekholm
|
|
|
I'll pass this webp image to the JDeli team that develops the codec for WebP. What software did you use to produce it?
I used "PhotoFiltre 11", Version 11.2.0 (64-bit) http://www.photofiltre.com/
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
6 Oct 22, 18:06
in response to: davidekholm
|
|
|
Markus, I've analyzed your lifeboat file. If my calculations are right, you have 1916 images that are affected by "order by camera date", so on each album build, 1916 images are opened and parsed for camera dates before operation can continue. This could potentially be the cause of the slowdown. The "Cache image ordering" simply switches to "Custom ordering" everywhere, but naturally maintains the same ordering as "Camera ordering" has generated right now so you should be able to run this tool safely.
Hi David,
yesterday:
Making deep-data.json: 1,296s
"Norge, Sverige, Danmark, Suomi" erzeugt in 10m 53,041s
Compiling C:\Users\MDr�ck\AppData\Roaming\JAlbum\skins\Tiger\finally.js
Today I used the tool "Cache image ordering". Result was "Processed 517 objects in 59,986s".
Then compiled again:
Making deep-data.json: 1,163s
"Norge, Sverige, Danmark, Suomi" erzeugt in 18m 6,868s
Compiling C:\Users\MDr�ck\AppData\Roaming\JAlbum\skins\Tiger\finally.js
Not quite what we expected?
Just a stupid question, but what exactly is JA doing during the compilation? Is it accessing/reading the picture files (and videos etc.)? I'm asking because I see messages like "Metadaten aus Bildern auslesen..." which is "engine.readingMetadataInfo=Reading image metadata...". But why should JA read the metadata from the picture every time during compilation?
If I'm looking in a file like "P1300250.JPG.info" I see: <?xml version="1.0" encoding="UTF-8"?>
<java version="14.0.2" class="java.beans.XMLDecoder">
<object class="java.util.HashMap">
<void method="put">
<string>keywords</string>
<string>2022, Deutschland, Fähre</string>
</void>
<void method="put">
<string>title</string>
<string>Hahnstätten – Puttgarden – <i class='fa fa-ship'>&nbsp;</i> – Rødby – Malmö</string>
</void>
</object>
</java>
Wouldn't it make sense to read the metadata once from the picture and write it to the corresponding .info file and from that time on read the metadata from the .info file? Except, when the picture has been changed since the last compilation. Assuming that reading the metadata is much faster from a small text file instead of several mega bytes of a picture. Just a thought from my side.
|
|
|
Posts:
3,442
Registered:
18-Oct-2002
|
|
|
Re: Time stamp in the console
Posted:
6 Oct 22, 18:50
in response to: MarkusD
|
|
|
It's a good thought Markus, and I've been thinking about caching metadata too in smaller files, but using the .info files would most definitely generate one extra file for each image, but it may be worth it.
Can you generate 2-3 of those "thread dump" files I asked about so we can ensure that jAlbum is indeed taking most of the time parsing image metadata?
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
6 Oct 22, 19:07
in response to: davidekholm
|
|
|
It's a good thought Markus, and I've been thinking about caching metadata too in smaller files, but using the .info files would most definitely generate one extra file for each image, but it may be worth it.
Can you generate 2-3 of those "thread dump" files I asked about so we can ensure that jAlbum is indeed taking most of the time parsing image metadata?
Sorry David, I forgot about the thread dumps. Please find them here:
https://www.markus-drueck.de/JA/thread%20dump-MD.zip
This time I got an error message: An unexpected error occurred. Please see detailed description below:
java.lang.RuntimeException: Error processing D:\Eigene Dateien\MDrück\Pictures\2009 02 27 Norge\Prolog
at se.datadosen.jalbum.AlbumBean.registerVariables(AlbumBean.java:2806)
at se.datadosen.jalbum.AlbumObjectImpl.getVars(AlbumObjectImpl.java:2800)
at org.openjdk.nashorn.internal.scripts.Script$Recompilation$117$97090AD$util.getDropdownMenu#getSubMenu(C:\Users\MDrück\AppData\Roaming\JAlbum\skins\Tiger\lib\util.js:3989)
at org.openjdk.nashorn.internal.scripts.Script$Recompilation$117$97090AD$util.getDropdownMenu#getSubMenu(C:\Users\MDrück\AppData\Roaming\JAlbum\skins\Tiger\lib\util.js:3994)
at org.openjdk.nashorn.internal.scripts.Script$Recompilation$115$96341AAAAADZA$util.getDropdownMenu(C:\Users\MDrück\AppData\Roaming\JAlbum\skins\Tiger\lib\util.js:4014)
at org.openjdk.nashorn.internal.scripts.Script$Recompilation$94$7842A$init.processFolder#L:241(C:\Users\MDrück\AppData\Roaming\JAlbum\skins\Tiger\init.js:392)
at org.openjdk.nashorn.javaadapters.java_util_function_Consumer.accept(Unknown Source)
at java.base/java.util.ArrayList.forEach(Unknown Source)
at org.openjdk.nashorn.internal.scripts.Script$Recompilation$90$6422A$init.processFolder(C:\Users\MDrück\AppData\Roaming\JAlbum\skins\Tiger\init.js:241)
at org.openjdk.nashorn.internal.scripts.Script$89$predir.:program(C:\Users\MDrück\AppData\Roaming\JAlbum\skins\Tiger\predir.js:5)
at org.openjdk.nashorn.internal.runtime.ScriptFunctionData.invoke(ScriptFunctionData.java:646)
at org.openjdk.nashorn.internal.runtime.ScriptFunction.invoke(ScriptFunction.java:513)
at org.openjdk.nashorn.internal.runtime.ScriptRuntime.apply(ScriptRuntime.java:520)
at org.openjdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:442)
at org.openjdk.nashorn.api.scripting.NashornScriptEngine$1.eval(NashornScriptEngine.java:503)
at java.scripting/javax.script.CompiledScript.eval(Unknown Source)
at se.datadosen.jalbum.AlbumBean.processExpression(AlbumBean.java:3021)
at se.datadosen.jalbum.AlbumBean.processScript(AlbumBean.java:2936)
at se.datadosen.jalbum.AlbumBean.makeAlbumForFolder(AlbumBean.java:1846)
at se.datadosen.jalbum.AlbumBean.makeAlbum(AlbumBean.java:3266)
at se.datadosen.jalbum.AlbumBean.smartMakeAlbum(AlbumBean.java:3158)
at se.datadosen.jalbum.JAlbumFrame$7.run(JAlbumFrame.java:1170)
Caused by: java.lang.NullPointerException: Cannot read field "width" because "newDim" is null
at se.datadosen.jalbum.ImageRenderer.computeRenditions(ImageRenderer.java:282)
at se.datadosen.jalbum.ImageRenderer.<init>(ImageRenderer.java:102)
at se.datadosen.jalbum.AlbumObjectImpl.getRenderer(AlbumObjectImpl.java:218)
at se.datadosen.jalbum.AlbumBean.addFilteredImageSizes(AlbumBean.java:3952)
at se.datadosen.jalbum.AlbumBean.registerVariables(AlbumBean.java:2790)
... 21 more
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
6 Oct 22, 19:15
in response to: davidekholm
|
|
|
It's a good thought Markus, and I've been thinking about caching metadata too in smaller files, but using the .info files would most definitely generate one extra file for each image, but it may be worth it.
This would make no difference for me. I do have a .info file for every picture, video etc. anyway. Because I use Titles and Keywords for all of them. JA shouldn't even start to compile unless every object has a Title, Comment and Keyword by the way.
It is like in LOTR:
“Ein Ring sie zu knechten, ....“
“One Ring to rule them all, ....“
I would rule the JA users to use the product properly. Just kidding.
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
6 Oct 22, 19:24
in response to: davidekholm
|
|
|
It's a good thought Markus, and I've been thinking about caching metadata too in smaller files, but using the .info files would most definitely generate one extra file for each image, but it may be worth it.
Joking aside, that each image (and video, etc.) gets its own .info file is indeed not entirely uncritical, because we all know that it is much more time-critical to process 1,000 small files than one file that contains all the information. But I guess it is more clever to have a single file for each image. But it's hard for me to estimate.
What I've noticed, for example, is that if I give a comment to all the images in a folder with, say, 100 images (for the first time), then it takes a few seconds. After all, 100 files have to be created first. This would certainly go much faster if the comments would all be managed in one file (per folder).
|
|
|
Posts:
3,442
Registered:
18-Oct-2002
|
|
|
Re: Time stamp in the console
Posted:
6 Oct 22, 22:03
in response to: MarkusD
|
|
|
Thanks for the thread dumps Markus. It's indeed the camera dates that are causing the delay. Not when sorting, but when discovering first and last dates of images per folder. The key method call is doGetDeepCameraDates. I'll work on better caching.
|
|
|
Posts:
3,442
Registered:
18-Oct-2002
|
|
|
Re: Time stamp in the console
Posted:
12 Oct 22, 14:50
in response to: davidekholm
|
|
|
@Markus, can you set jAlbum's logging level to "FINER" and retry the make album process, then tell me just how many "Cache miss for <folder name>" your're getting in the system console. It seems to me that the cacheing of camera dates isn't working properly. There is a folder-level cache.
When done, make the album again, just to ensure that the cache is indeed broken. If it's working, then the build times should be far shorter.
Are you using a high number of PNG files in your gallery? If so, please pass me one such PNG image for inspection.
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
12 Oct 22, 19:21
in response to: davidekholm
|
|
|
@Markus, can you set jAlbum's logging level to "FINER" and retry the make album process, then tell me just how many "Cache miss for <folder name>" your're getting in the system console. It seems to me that the cacheing of camera dates isn't working properly. There is a folder-level cache.
I don't see any "Cache miss for" messages.
When done, make the album again, just to ensure that the cache is indeed broken. If it's working, then the build times should be far shorter.
I've done that. Compiling the first time: 14m 43,161s. Compiling the second time: 9m 52,987s. Nevertheless, this is far away from what I would call "fast". Maybe I'm expecting too much. But I have read some older posts where other users reporting that compiling albums with several thousands pictures takes only several seconds.
The complete log files:
https://www.markus-drueck.de/JA/2022%2010%2012%2018%2044%20-%20Compiling%20first%20time.txt
https://www.markus-drueck.de/JA/2022%2010%2012%2019%2001%20-%20Compiling%20second%20time.txt
Are you using a high number of PNG files in your gallery? If so, please pass me one such PNG image for inspection.
Hard to say how may PNG files I have in my gallery. Several hundreds (out of 8.220). At least 1.788 PNG are in this folder https://www.markus-drueck.de/norge/Misc/Finse/index.html.
I ZIPed one of the folders with PNG files:
https://www.markus-drueck.de/JA/2022%2099%20Finse.zip
Thanks, Markus
|
|
|
Posts:
3,442
Registered:
18-Oct-2002
|
|
|
Re: Time stamp in the console
Posted:
19 Oct 22, 13:05
in response to: MarkusD
|
|
|
Hi Markus. I've been investigating the performance issue and made some improvements. Please reinstall jAlbum 29 from our site. This will give you v29.0.2. Now make the album again. What timings do you get now? (Printed to jAlbum's system console window)
v29.0.2 also does more detailed profiling on how much time jAlbum spends in various code sections during album build. This info can help me identify performance issues. To print detailed profiling data for the last album build, open the system console and issue Profiler.instance
then pass me the generated report. More details on the profiler here: https://jalbum.net/forum/thread.jspa?threadID=58577&tstart=0
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
19 Oct 22, 21:01
in response to: davidekholm
|
|
|
Hi David,
compiling the album having changed the "variants". So I expected a long compilation time:
"Norge, Sverige, Danmark, Suomi" erzeugt in 41m 42,348s
Profiler.instance: 0,632s ==>
FileFilters.saveImage: 28507 calls 27m 6,814s
FileFilters.loadImage: 7207 calls 12m 21,387s
AlbumObjectImpl.getMetadata: 11189 calls 5m 17,207s
AlbumBean.registerVariables: 10747 calls 4m 45,926s
HardwareSmoothScaler.scale: 12670 calls 4m 13,401s
JAlbumUtilities.getDeepCameraDates: 519 calls 3m 21,097s
AlbumObjectImpl.getXmpManager: 12703 calls 2m 34,702s
AlbumObjectImpl.getProperties: 10203 calls 1m 23,569s
RecoveryTool.createLifeboat: 1 calls 1m 23,55s
AlbumObjectProperties.load: 9954 calls 1m 5,415s
FileFilters.unifyColorModel: 7207 calls 36,152s
AlbumBean.makeIndexPages: 519 calls 28,86s
FileFilters.getBasicImageInfo: 9764 calls 22,597s
AlbumBean.processFilters: 35759 calls 21,349s
AlbumBean.countChangedFiles: 1 calls 12,3s
Create MediaRSS: 519 calls 7,841s
AlbumBean.getFolderProperties: 2674 calls 6,302s
JAlbumUtilities.countCategories: 4171 calls 6s
init: 1 calls 0,792s
JAlbumUtilities.countWebLocationCategories: 408 calls 0,256s
copy res files: 1 calls 0,016s
Total: 164724 calls 65m 55,533s
Compiling the album again, nothing changed, no new pictures, no new videos:
"Norge, Sverige, Danmark, Suomi" erzeugt in 6m 54,677s
Profiler.instance: 0,66s ==>
AlbumObjectImpl.getMetadata: 11073 calls 4m 3,291s
AlbumBean.registerVariables: 10746 calls 3m 55,539s
RecoveryTool.createLifeboat: 1 calls 51,362s
AlbumBean.makeIndexPages: 519 calls 17,408s
FileFilters.saveImage: 54 calls 16,806s
FileFilters.getBasicImageInfo: 9763 calls 16,732s
AlbumObjectImpl.getProperties: 9795 calls 16,019s
AlbumObjectProperties.load: 9626 calls 14,117s
AlbumObjectImpl.getXmpManager: 12702 calls 9,623s
JAlbumUtilities.getDeepCameraDates: 519 calls 6,27s
HardwareSmoothScaler.scale: 25 calls 4,628s
AlbumBean.countChangedFiles: 1 calls 4,539s
Create MediaRSS: 519 calls 3,805s
FileFilters.loadImage: 35 calls 3,575s
JAlbumUtilities.countCategories: 4171 calls 2,981s
AlbumBean.getFolderProperties: 2674 calls 2,398s
init: 1 calls 0,738s
JAlbumUtilities.countWebLocationCategories: 408 calls 0,193s
FileFilters.unifyColorModel: 35 calls 0,186s
copy res files: 1 calls 0,016s
AlbumBean.processFilters: 56 calls 0,003s
Total: 72724 calls 10m 50,229s
Recompiling in the past lasts minimum more than 12 minutes, now approx 7 minutes. This is a significant performance improvement! Well done David. Thanks.
|
|
|
Posts:
3,442
Registered:
18-Oct-2002
|
|
|
Re: Time stamp in the console
Posted:
19 Oct 22, 22:46
in response to: MarkusD
|
|
|
Thank you. Great to see! I'll see if I can polish things further. You'll likely get a significant speed boost if you can make that gallery on an SSD.
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
20 Oct 22, 20:23
in response to: davidekholm
|
|
|
You'll likely get a significant speed boost if you can make that gallery on an SSD.
Yes, no doubt about it.
The current PC (running Windows 10) I'm working on (about 7 years old) already has a SSD as the main drive with drive "C:", with a capacity of 512 GB. And there is a second SSD with 1 TB, which holds several virtual machines (VMware). But the Pictures folder is on a 10 TB HDD. And I'm not sure if I should go for a SSD which stores also the Picture folder, right now this folder is about 1,5 TB of data. So I would end up in needing a SSD with a minimum size of 2 TB, and from 2024 on I'm doomed to not travel any more and take pictures and videos. I think you get the idea.
|
|
|
Posts:
3,442
Registered:
18-Oct-2002
|
|
|
Re: Time stamp in the console
Posted:
21 Oct 22, 14:43
in response to: MarkusD
|
|
|
I've been polishing jAlbum's performance further now speeding up the counting of total # of files. On a large network based project, I cut the counting time to 1/4 (from 40s to 10s). Just do a core update to get v29.0.3 which features this faster total file counting (done while initiating an album build)
|
|
|
Posts:
661
Registered:
13-Apr-2006
|
|
|
Re: Time stamp in the console
Posted:
21 Oct 22, 19:26
in response to: davidekholm
|
|
|
Hi David,
compiling the album with 29.0.2
"Norge, Sverige, Danmark, Suomi" erzeugt in 6m 54,677s
Profiler.instance: 0,66s ==>
AlbumObjectImpl.getMetadata: 11073 calls 4m 3,291s
AlbumBean.registerVariables: 10746 calls 3m 55,539s
RecoveryTool.createLifeboat: 1 calls 51,362s
AlbumBean.makeIndexPages: 519 calls 17,408s
FileFilters.saveImage: 54 calls 16,806s
FileFilters.getBasicImageInfo: 9763 calls 16,732s
AlbumObjectImpl.getProperties: 9795 calls 16,019s
AlbumObjectProperties.load: 9626 calls 14,117s
AlbumObjectImpl.getXmpManager: 12702 calls 9,623s
JAlbumUtilities.getDeepCameraDates: 519 calls 6,27s
HardwareSmoothScaler.scale: 25 calls 4,628s
AlbumBean.countChangedFiles: 1 calls 4,539s
Create MediaRSS: 519 calls 3,805s
FileFilters.loadImage: 35 calls 3,575s
JAlbumUtilities.countCategories: 4171 calls 2,981s
AlbumBean.getFolderProperties: 2674 calls 2,398s
init: 1 calls 0,738s
JAlbumUtilities.countWebLocationCategories: 408 calls 0,193s
FileFilters.unifyColorModel: 35 calls 0,186s
copy res files: 1 calls 0,016s
AlbumBean.processFilters: 56 calls 0,003s
Total: 72724 calls 10m 50,229s
Compiling the album with 29.0.4
"Norge, Sverige, Danmark, Suomi" erzeugt in 8m 38,721s
Profiler.instance: 0,72s ==>
AlbumBean.registerVariables: 10746 calls 4m 42,822s
AlbumObjectImpl.getMetadata: 11277 calls 4m 41,437s
AlbumObjectImpl.getProperties: 9794 calls 1m 7,768s
RecoveryTool.createLifeboat: 1 calls 1m 6,785s
AlbumObjectProperties.load: 9625 calls 51,497s
AlbumBean.makeIndexPages: 519 calls 26,81s
FileFilters.getBasicImageInfo: 9763 calls 18,959s
AlbumBean.getFolderProperties: 2678 calls 18,328s
FileFilters.saveImage: 62 calls 17,386s
AlbumObjectImpl.getXmpManager: 12702 calls 11,486s
AlbumBean.countTotalFiles: 1 calls 9,49s
JAlbumUtilities.getDeepCameraDates: 519 calls 8,198s
Create MediaRSS: 519 calls 6,162s
HardwareSmoothScaler.scale: 25 calls 4,914s
JAlbumUtilities.countCategories: 4171 calls 4,375s
FileFilters.loadImage: 37 calls 3,646s
init: 1 calls 0,774s
JAlbumUtilities.countWebLocationCategories: 408 calls 0,378s
FileFilters.unifyColorModel: 37 calls 0,37s
copy res files: 1 calls 0,014s
AlbumBean.processFilters: 66 calls 0,004s
Total: 72952 calls 14m 41,603s
|
|
|
|
Legend
|
|
Forum admins
|
|
Helpful Answer
|
|
Correct Answer
|
|