Hi,
it looks like, that all is working quicker! ;)
Short question: If I have choosen 3 pic-layout, only one pic selcted and start the viewer, then the selected pic is in the middle of the three, not at the beginning. Is that so wanted and ok?
When you open the viewer, it navigates to the focused file. Depending on how you selected your files, the focused file can be the first, the last or one in the middle.
This allows you to control which image comes up first in the Viewer.
Quoteit looks like, that all is working quicker!
Tip: Near the end of the log file you'll find entries starting with #STA#.
You can copy/paste these statistics from a few of your sessions (adding files, working with IMatch 5). This gives me some feedback on how the different parts behave on your system and how the average processing times are.
Quote from: Mario on October 08, 2013, 08:39:11 PM
Tip: Near the end of the log file you'll find entries starting with #STA#.
You can copy/paste these statistics from a few of your sessions (adding files, working with IMatch 5). This gives me some feedback on how the different parts behave on your system and how the average processing times are.
Should that be #STS#?
I can't find #STA# in my log files...
Hi Mario,
do you mean like this? I did this with Excel and filtering. After the single S is normaly a >, I used it at separation, so it is not visible.
10.08 19:06:44+ 0 [1D44] 00 S #STS#: "engine.uptime"
10.08 19:06:44+ 0 [1D44] 00 S #STS#: "engine.uptime"
10.08 19:07:05+ 0 [0958] 00 S #STS#: "metabase.loadtime"
10.08 19:07:15+ 9157 [1D44] 00 S #STS#: "timeline.loadtime"
10.08 19:07:15+ 0 [1D44] 00 S #STS#: "engine.loadtime"
10.08 19:09:12+ 0 [1D44] 00 S #STS#: "engine.uptime"
10.08 19:09:12+ 0 [1D44] 00 S #STS#: "engine.uptime"
10.08 19:09:12+ 0 [1D44] 00 S #STS#: "engine.uptime"
10.08 19:09:15+ 0 [20E4] 00 S #STS#: "metabase.loadtime"
10.08 19:09:16+ 219 [1D44] 00 S #STS#: "timeline.loadtime"
10.08 19:09:16+ 0 [1D44] 00 S #STS#: "engine.loadtime"
I found also a lot of lines like this:
10.08 19:06:33+ 0 [1D44] 10 M < 7 [16ms] CIMSQLite::InnerOpen
10.08 19:06:33+ 0 [1D44] 10 M < 6 [16ms] CIMSQLite::GrowInstancePool
10.08 19:06:33+ 0 [1D44] 10 M < 5 [16ms] CIMSQLite::Open
10.08 19:06:33+ 0 [1D44] 05 M < 4 [16ms] PTSettingsStore::Open
10.08 19:06:33+ 0 [1D44] 05 I Attaching settings [settings]
10.08 19:06:33+ 0 [1D44] 00 M < 3 [16ms] CIMatchApp::OpenSettingsStore
10.08 19:06:34+ 140 [1D44] 00 M < 6 [140ms] PTRMLoader::OpenXML
10.08 19:06:34+ 94 [1D44] 02 M < 6 [94ms] PTRMLoader::LoadCommandTable
10.08 19:06:34+ 0 [1D44] 02 M < 6 [32ms] PTRMLoader::LoadMenuTable
10.08 19:06:34+ 499 [1D44] 02 M < 6 [499ms] PTRMLoader::LoadBitmapTable
10.08 19:06:34+ 47 [1D44] 00 M < 7 [47ms] PTRMLoader::OpenXML
10.08 19:06:34+ 15 [1D44] 02 M < 7 [15ms] PTRMLoader::LoadStringTable
10.08 19:06:34+ 16 [1D44] 00 M < 6 [78ms] PTRMLoader::LoadStringTable
10.08 19:06:34+ 31 [1D44] 00 M < 7 [31ms] PTRMLoader::OpenXML
10.08 19:06:34+ 16 [1D44] 02 M < 7 [16ms] PTRMLoader::LoadMessageTable
10.08 19:06:34+ 0 [1D44] 00 M < 6 [47ms] PTRMLoader::LoadMessageTable
10.08 19:06:34+ 78 [1D44] 00 M < 7 [78ms] PTRMLoader::OpenXML
10.08 19:06:34+ 62 [1D44] 02 M < 7 [62ms] PTRMLoader::LoadDialogTable
10.08 19:06:35+ 0 [1D44] 00 M < 6 [140ms] PTRMLoader::LoadDialogTable
10.08 19:06:35+ 31 [1D44] 02 M < 6 [31ms] PTRMLoader::LoadObjPropsTable
10.08 19:06:35+ 32 [1D44] 00 M < 5 [1170ms] PTRMLoader::Load
10.08 19:06:35+ 0 [1D44] 00 M < 4 [1170ms] PTResManager::Load
10.08 19:06:35+ 31 [1D44] 00 M < 3 [1201ms] CIMResManager::Load
This does not help. The important numbers after the #STA# entries are missing.
You don't need Excel. Just open the log in Notepad, scroll down to the end, scroll up a few pages until you find the #STA# block starting with engine.uptime and then copy/paste the entire rows. This will give me the numbers I need.
Hi Mario,
as jch2103 mentioned, it is STS and "engine.uptime"is needde for search:
10.09 08:59:19+ 0 [1D00] 00 S> #STS#: "engine.uptime" 0 0 0,00 "08:59:19"
10.09 08:59:19+ 0 [1D00] 10 M> > 5 PTFileSystemMonitor::Enable 'PTFileSystemMonitor.cpp(755)'
10.09 08:59:19+ 0 [1D00] 10 M> < 5 PTFileSystemMonitor::Enable
10.09 08:59:19+ 0 [1D00] 00 M> < 4 [47ms] CIMEngine5::Close
10.09 08:59:19+ 78 [1D00] 00 M> < 3 [172ms] CMainFrame::CloseDatabase
10.09 08:59:19+ 0 [1D00] 00 M> > 3 CIMEngine5::Open 'IMEngine5.cpp(2481)'
10.09 08:59:19+ 0 [1D00] 10 M> > 4 PTFileSystemMonitor::Enable 'PTFileSystemMonitor.cpp(755)'
10.09 08:59:19+ 0 [1D00] 10 M> < 4 PTFileSystemMonitor::Enable
10.09 08:59:19+ 0 [1D00] 00 M> > 4 CIMEngine5::Close 'IMEngine5.cpp(3123)'
10.09 08:59:19+ 0 [1D00] 00 M> > 5 PTMDTemplateManager::Close 'PTMDTemplate.cpp(295)'
10.09 08:59:19+ 0 [1D00] 00 M> < 5 PTMDTemplateManager::Close
10.09 08:59:19+ 0 [1D00] 00 S> #STS#: "engine.uptime" 0 0 0,00 "08:59:19"
10.09 08:59:19+ 0 [1D00] 00 M> < 4 CIMEngine5::Close
Hmm ... both are the same ... and only zeros ...
I used Excel to filter the lines because there where more than 600.000 lines in the log-file and the default notepad is soooo slow.
May be an idea to make the used text-editor configurable in the preferences, because there are much more quicker ones, e.g. TextPad
Quote from: Gerd on October 09, 2013, 09:32:03 AM
Hi Mario,
as jch2103 mentioned, it is STS and "engine.uptime"is needde for search:
Don't filter on "engine.uptime", there are different values to look for: "engine.loadtime", "timeline.loadtime", "metabase.loadtime" ...
QuoteMay be an idea to make the used text-editor configurable in the preferences, because there are much more quicker ones, e.g. TextPad
I believe the default editor for "txt" files is used. Change it to TextPad in your OS.
Hi,
I'm a little bit an Excel-expert, because there it is so easy to find and select data ...
Here what I found in the "Log from Today" and contains "time":
10.09 08:58:50+ 0 [1D00] 00 I> Time Zone Information: Bias: -60, Daylight-Bias: -60. Full Bias: -120.
10.09 08:58:51+ 0 [1D00] 10 I> Loading timezone_table
10.09 08:59:19+ 0 [1D00] 00 S> #STS#: "engine.uptime" 0 0 0 8:59:19
10.09 08:59:19+ 0 [1D00] 00 S> #STS#: "engine.uptime" 0 0 0 8:59:19
10.09 08:59:36+ 0 [1FFC] 00 S> #STS#: "metabase.loadtime" 0 0 0 4633ms
10.09 08:59:36+ 15 [1D00] 00 M> > 4 CIMTimeline::Open 'IMTimeLine.cpp(400)'
10.09 08:59:36+ 0 [1D00] 00 M> > 5 CIMTimeline::Close 'IMTimeLine.cpp(560)'
10.09 08:59:36+ 0 [1D00] 00 M> < 5 CIMTimeline::Close
10.09 09:00:02+25709 [1D00] 00 S> #STS#: "timeline.loadtime" 0 0 0 25709ms
10.09 09:00:02+ 0 [1D00] 00 M> < 4 [25709ms] CIMTimeline::Open
10.09 09:00:02+ 0 [1D00] 00 S> #STS#: "engine.loadtime" 0 0 0 43150ms
10.09 09:00:19+ 0 [1D00] 10 M> > 16 CViewPaneTimelineCtrl::Load 'ViewPaneTimelineCtrl.cpp(595)'
10.09 09:00:19+ 0 [1D00] 10 M> > 17 CTimelineWnd::Load 'TimelineWnd.cpp(1901)'
10.09 09:00:20+ 905 [1D00] 10 M> < 17 [905ms] CTimelineWnd::Load
10.09 09:00:21+ 624 [1D00] 10 M> < 16 [1529ms] CViewPaneTimelineCtrl::Load
Still a log of the important values missing. I just open the file in Notepad, scroll down and then up. There is an entire block of stats, e.g.
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "app.fw.loadg.avg" 2 93 46,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "app.fw.loadg.max" 62 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "collections.calc.avg" 10 31 3,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "collections.calc.max" 31 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "collections.load.avg" 2 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "collections.load.max" 0 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "engine.idledelegate.avg" 15 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "engine.idledelegate.max" 0 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "engine.loadtime" 0 0 0,00 "3604ms"
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "engine.uptime" 0 0 0,00 "00:02:42"
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "grouper.loadcache.avg" 2 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "grouper.loadcache.max" 0 0 0,00 ""
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "metabase.loadtime" 0 0 0,00 "2527ms"
10.08 18:07:42+ 0 [1200] 00 S> #STS#: "timeline.loadtime" 0 0 0,00 "0ms"
That's the data I'm after, especially when you also added files. There will be more values then. I need the entire block or just ZIP/attach your entire log and I'll look myself.
Here the log from yesterday and today.
[attachment deleted by admin]
I don't have that block / values. Tried with normal and debug logging.
Anything to configure somewhere?
The stats are written to the log file when IMatch closes.
The two attached log files show IMatch still running...
Now I closed IM5 and attched the log-file, which I found in user-temp.
[attachment deleted by admin]
Here the log after new start.
For what are the 4 min needed here (screenshot extract log-file)?
[attachment deleted by admin]
Hi Mario,
here are my stats:
#STS#: "app.fw.loadg.avg" 312 119894 384,00 ""
#STS#: "app.fw.loadg.max" 11341 0 0,00 ""
#STS#: "collections.calc.avg" 1220 319844 262,00 ""
#STS#: "collections.calc.max" 17894 0 0,00 ""
#STS#: "collections.load.avg" 1 0 0,00 ""
#STS#: "collections.load.max" 0 0 0,00 ""
#STS#: "collections.store.avg" 115 110 0,00 ""
#STS#: "collections.store.max" 32 0 0,00 ""
#STS#: "engine.idledelegate.avg" 350 31190 89,00 ""
#STS#: "engine.idledelegate.max" 3463 0 0,00 ""
#STS#: "engine.loadtime" 0 0 0,00 "3931ms"
#STS#: "engine.upq.core.avg" 48 868331 18090,00 ""
#STS#: "engine.upq.core.max" 38423 0 0,00 ""
#STS#: "engine.upq.fts.avg" 70 67375 962,00 ""
#STS#: "engine.upq.fts.max" 11606 0 0,00 ""
#STS#: "engine.upq.meta.avg" 93 1778936 19128,00 ""
#STS#: "engine.upq.meta.max" 131821 0 0,00 ""
#STS#: "engine.upq.relman.avg" 13 11719 901,00 ""
#STS#: "engine.upq.relman.max" 1233 0 0,00 ""
#STS#: "engine.uptime" 0 0 0,00 "14:22:15"
#STS#: "grouper.loadcache.avg" 1 0 0,00 ""
#STS#: "grouper.loadcache.max" 0 0 0,00 ""
#STS#: "grouper.refreshgroup.avg" 90 64012 711,00 ""
#STS#: "grouper.refreshgroup.max" 11575 0 0,00 ""
#STS#: "meta.etx.avg" 91 1477503 16236,00 ""
#STS#: "meta.etx.max" 130635 0 0,00 ""
#STS#: "meta.importfiles.avg" 91 63098 693,00 ""
#STS#: "meta.importfiles.max" 9141 0 0,00 ""
#STS#: "meta.writeback.avg" 35 1085428 31012,00 ""
#STS#: "meta.writeback.max" 374995 0 0,00 ""
#STS#: "metabase.loadtime" 0 0 0,00 "3355ms"
#STS#: "timeline.loadtime" 0 0 0,00 "47ms"
QuoteFor what are the 4 min needed here (screenshot extract log-file)?
That's only 4 seconds (about 4000 milliseconds).
Quotehere are my stats:
Thanks. Interesting.
Quote from: joel23 on October 09, 2013, 02:26:31 PM
Hi Mario,
here are my stats:
Interesting, because then I can compare a little bit with my values (of course this cannot be a direct comparison). But I can see, how slow my machine is ;)
Quote from: sinus on October 09, 2013, 05:06:51 PM
Quote from: joel23 on October 09, 2013, 02:26:31 PM
Hi Mario,
here are my stats:
Interesting, because then I can compare a little bit with my values (of course this cannot be a direct comparison). But I can see, how slow my machine is ;)
Tss, let us see ;)
EDIT: not sure the values are useful at the moment. For me IM loops again with V118 when metadata should be written back. Often they are written and only the pencil resist, but sometimes its loops until I empty the queue.
If it helps, here are stats from my notebook after adding a video file to IMatch. (Win8/64, I5 processor, 8GB RAM, 256GB SSD)
[attachment deleted by admin]
And stats from my desktop, also after adding one video. (Win7/64, I7 Q6600 processor, 6GB RAM, 256GB SSD, 2TB hard disk)
[attachment deleted by admin]
Quote from: joel23 on October 09, 2013, 05:17:04 PM
Quote from: sinus on October 09, 2013, 05:06:51 PM
Quote from: joel23 on October 09, 2013, 02:26:31 PM
Hi Mario,
here are my stats:
Interesting, because then I can compare a little bit with my values (of course this cannot be a direct comparison). But I can see, how slow my machine is ;)
Tss, let us see ;)
EDIT: not sure the values are useful at the moment. For me IM loops again with V118 when metadata should be written back. Often they are written and only the pencil resist, but sometimes its loops until I empty the queue.
What does loop mean? Does it attempt to write the same file over and over again? What is the log file and the ExifTool output panel saying? I cannot find this problem without info. Or have you reported this already? Then a link to your original bug report would help.
Mario,
thought I better answer you in the former thread about that -> https://www.photools.com/community/index.php?topic=955.0
Very good. I know I remembered that error from somewhere...
Hi Mario,
thought you might be interested in getting some another results:
#STS#: "app.fw.loadg.avg" 1061 158149 149,00 ""
#STS#: "app.fw.loadg.max" 4180 0 0,00 ""
#STS#: "collections.calc.avg" 2214 345774 156,00 ""
#STS#: "collections.calc.max" 9782 0 0,00 ""
#STS#: "collections.load.avg" 3 0 0,00 ""
#STS#: "collections.load.max" 0 0 0,00 ""
#STS#: "collections.store.avg" 18 63 3,00 ""
#STS#: "collections.store.max" 16 0 0,00 ""
#STS#: "engine.idledelegate.avg" 8949 0 0,00 ""
#STS#: "engine.idledelegate.max" 0 0 0,00 ""
#STS#: "engine.loadtime" 0 0 0,00 "2262ms"
#STS#: "engine.upq.core.avg" 299 5142073 17197,00 ""
#STS#: "engine.upq.core.max" 88999 0 0,00 ""
#STS#: "engine.upq.fts.avg" 553 324113 586,00 ""
#STS#: "engine.upq.fts.max" 13354 0 0,00 ""
#STS#: "engine.upq.meta.avg" 673 11545855 17155,00 ""
#STS#: "engine.upq.meta.max" 71043 0 0,00 ""
#STS#: "engine.upq.relman.avg" 58 548731 9460,00 ""
#STS#: "engine.upq.relman.max" 37971 0 0,00 ""
#STS#: "engine.uptime" 0 0 0,00 "21:58:24"
#STS#: "grouper.loadcache.avg" 3 0 0,00 ""
#STS#: "grouper.loadcache.max" 0 0 0,00 ""
#STS#: "grouper.refreshgroup.avg" 231 86365 373,00 ""
#STS#: "grouper.refreshgroup.max" 3931 0 0,00 ""
#STS#: "meta.etx.avg" 679 10951631 16129,00 ""
#STS#: "meta.etx.max" 70310 0 0,00 ""
#STS#: "meta.importfiles.avg" 679 309692 456,00 ""
#STS#: "meta.importfiles.max" 3307 0 0,00 ""
#STS#: "meta.writeback.avg" 96 2807532 29245,00 ""
#STS#: "meta.writeback.max" 400080 0 0,00 ""
#STS#: "metabase.loadtime" 0 0 0,00 "1529ms"
#STS#: "timeline.loadtime" 0 0 0,00 "16ms"
General Database Info:
Database file name: C:\imatch\new.imd5
Database file size on disk: 2,33 GB
Number of folders: 335
Number of files: 19.711
Number of categories: 7.287
Windows 7, Version: 6.1, Build 7601, Service Pack 1 , 64bit, 8Gb,
Processor Architecture: 0, Number of processors: 6, type: 586, level: 000015, revision: 258
DB on SystemDrive which is a SSD
Cache on USB 3 HDD
Images on SATA 2 HDDs
Seems since I don't have the loop prob anymore, some things are loading much faster, e.g. metabase.loadtime, timeline.loadtime, etc.