Viewer-v120, layout

Gerd · October 08, 2013, 07:20:23 PM

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?

Mario · October 08, 2013, 08:06:24 PM

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.

Mario · October 08, 2013, 08:39:11 PM

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.

jch2103 · October 08, 2013, 09:42:29 PM

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...

Gerd · October 08, 2013, 10:46:37 PM

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

Mario · October 09, 2013, 08:38:01 AM

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.

Gerd · October 09, 2013, 09:32:03 AM

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

joel23 · October 09, 2013, 10:08:56 AM

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.

Gerd · October 09, 2013, 10:49:36 AM

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

Mario · October 09, 2013, 12:06:56 PM

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.

Gerd · October 09, 2013, 12:12:53 PM

Here the log from yesterday and today.

[attachment deleted by admin]

joel23 · October 09, 2013, 12:31:20 PM

I don't have that block / values. Tried with normal and debug logging.
Anything to configure somewhere?

Mario · October 09, 2013, 01:54:53 PM

The stats are written to the log file when IMatch closes.
The two attached log files show IMatch still running...

Gerd · October 09, 2013, 02:00:15 PM

Now I closed IM5 and attched the log-file, which I found in user-temp.

[attachment deleted by admin]

Gerd · October 09, 2013, 02:17:28 PM

Here the log after new start.

For what are the 4 min needed here (screenshot extract log-file)?

[attachment deleted by admin]

joel23 · October 09, 2013, 02:26:31 PM

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"

Mario · October 09, 2013, 02:32:50 PM

QuoteFor what are the 4 min needed here (screenshot extract log-file)?

That's only 4 seconds (about 4000 milliseconds).

Mario · October 09, 2013, 02:35:21 PM

Quotehere are my stats:

Thanks. Interesting.

sinus · 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

joel23 · 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.

jch2103 · October 09, 2013, 05:18:15 PM

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]

jch2103 · October 09, 2013, 05:40:51 PM

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]

Mario · October 09, 2013, 09:10:30 PM

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.

joel23 · October 10, 2013, 08:45:36 PM

Mario,
thought I better answer you in the former thread about that -> https://www.photools.com/community/index.php?topic=955.0

Mario · October 11, 2013, 08:05:15 AM

Very good. I know I remembered that error from somewhere...

joel23 · October 16, 2013, 09:22:50 PM

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.