Long time to cache images?

Started by Jingo, September 16, 2015, 04:17:26 PM

Previous topic - Next topic
Print
Go Down Pages1
User actions

Jingo

September 16, 2015, 04:17:26 PM
Hi Mario - I have noticed that caching images is taking a very long time for some simple jpg files... was curious if the log file might show any issues with my Photos drive... curious on your thoughts.   My Photos drive is a 2TB 7200 while my catalog is on a 512 SSD..  The photo drive is running on my MAC machine on network with MACDRIVE running for access.

Here is a sample from a Select-all, Ctrl-F5:

09.16 10:04:09+ 5132 [418C0] 10  M>       <  6 [5132ms] PTPIP::LoadThumbnail
09.16 10:04:09+    0 [418C0] 10  I>          ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:09+    0 [418C0] 10  M>      <  5 [5132ms] PTPIImage::LoadFile
09.16 10:04:09+    0 [418C0] 10  I>     EUQH::Load(1) of P:\Images\Photos\2015\Apr\Canon PowerShot SX50 HS_0041.jpg with 4000 x 3000 (O: 4000 x 3000) in 5132ms
09.16 10:04:09+    0 [418C0] 10  M>      >  5 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:09+  421 [418C0] 10  M>      <  5 [421ms] CIMCacheManager::CreateCacheImage
09.16 10:04:09+    0 [418C0] 10  I>     EUQH: Time for file (23) 5600ms
09.16 10:04:10+   63 [418C0] 10  M>      >  5 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:10+    0 [418C0] 10  M>       >  6 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:14+ 4290 [418C0] 10  M>       <  6 [4290ms] PTPIP::LoadThumbnail
09.16 10:04:14+    0 [418C0] 10  I>          ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:14+    0 [418C0] 10  M>      <  5 [4290ms] PTPIImage::LoadFile
09.16 10:04:14+    0 [418C0] 10  I>     EUQH::Load(1) of P:\Images\Photos\2015\Apr\Canon PowerShot SX50 HS_0042.jpg with 4000 x 3000 (O: 4000 x 3000) in 4290ms
09.16 10:04:14+    0 [418C0] 10  M>      >  5 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:14+   78 [41C08] 10  M>      <  5 [20686ms #sl] PTPIP::LoadThumbnail
09.16 10:04:14+    0 [41C08] 10  I>         ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:14+    0 [41C08] 10  M>     <  4 [20811ms #sl] PTPIImage::LoadFile
09.16 10:04:14+    0 [41C08] 10  I>    EUQH::Load(1) of P:\Images\Photos\2015\May\Canon PowerShot SX50 HS_0087.jpg with 4000 x 3000 (O: 4000 x 3000) in 20811ms
09.16 10:04:14+    0 [41C08] 10  M>     >  4 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:14+  358 [418C0] 10  M>     <  4 [436ms] CIMCacheManager::CreateCacheImage
09.16 10:04:14+   16 [418C0] 10  I>    EUQH: Time for file (24) 4774ms
09.16 10:04:14+   47 [418C0] 10  M>     >  4 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:14+    0 [418C0] 10  M>      >  5 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:14+   93 [41C08] 10  M>      <  5 [514ms] CIMCacheManager::CreateCacheImage
09.16 10:04:14+    0 [41C08] 10  I>     EUQH: Time for file (62) 21574ms
09.16 10:04:14+   63 [41E40] 10  M>     <  4 [11154ms #sl] PTPIP::LoadThumbnail
09.16 10:04:14+    0 [41E40] 10  I>        ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:14+    0 [41E40] 10  M>    <  3 [11217ms #sl] PTPIImage::LoadFile
09.16 10:04:14+    0 [41E40] 10  I>   EUQH::Load(1) of P:\Images\Photos\2015\May\Canon PowerShot SX50 HS_0066.jpg with 3751 x 2813 (O: 3751 x 2813) in 11217ms
09.16 10:04:14+    0 [41E40] 10  M>    >  3 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:14+   15 [41C08] 10  M>     >  4 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:15+   94 [41C08] 10  M>      >  5 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:15+  359 [41E40] 10  M>      <  5 [468ms] CIMCacheManager::CreateCacheImage
09.16 10:04:15+    0 [41E40] 10  I>     EUQH: Time for file (43) 11794ms
09.16 10:04:15+  109 [41E40] 10  M>      >  5 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:15+   47 [41E40] 10  M>       >  6 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:18+ 2511 [418C0] 10  M>       <  6 [3291ms] PTPIP::LoadThumbnail
09.16 10:04:18+    0 [418C0] 10  I>          ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:18+    0 [418C0] 10  M>      <  5 [3291ms] PTPIImage::LoadFile
09.16 10:04:18+    0 [418C0] 10  I>     EUQH::Load(1) of P:\Images\Photos\2015\Apr\Canon PowerShot SX50 HS_0043.jpg with 4000 x 3000 (O: 4000 x 3000) in 3291ms
09.16 10:04:18+    0 [418C0] 10  M>      >  5 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:18+  344 [418C0] 10  M>      <  5 [344ms] CIMCacheManager::CreateCacheImage
09.16 10:04:18+    0 [418C0] 10  I>     EUQH: Time for file (25) 3651ms
09.16 10:04:18+   62 [418C0] 10  M>      >  5 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:18+    0 [418C0] 10  M>       >  6 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:22+ 3635 [41E40] 10  M>       <  6 [6552ms #sl] PTPIP::LoadThumbnail
09.16 10:04:22+    0 [41E40] 10  I>          ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:22+    0 [41E40] 10  M>      <  5 [6599ms #sl] PTPIImage::LoadFile
09.16 10:04:22+    0 [41E40] 10  I>     EUQH::Load(1) of P:\Images\Photos\2015\May\Canon PowerShot SX50 HS_0068.jpg with 4000 x 3000 (O: 4000 x 3000) in 6599ms
09.16 10:04:22+    0 [41E40] 10  M>      >  5 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:22+   16 [418C0] 10  M>      <  5 [3651ms] PTPIP::LoadThumbnail
09.16 10:04:22+    0 [418C0] 10  I>         ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:22+    0 [418C0] 10  M>     <  4 [3651ms] PTPIImage::LoadFile
09.16 10:04:22+    0 [418C0] 10  I>    EUQH::Load(1) of P:\Images\Photos\2015\Apr\Canon PowerShot SX50 HS_0044.jpg with 4000 x 3000 (O: 4000 x 3000) in 3651ms
09.16 10:04:22+    0 [418C0] 10  M>     >  4 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:22+  374 [418C0] 10  M>     <  4 [374ms] CIMCacheManager::CreateCacheImage
09.16 10:04:22+    0 [418C0] 10  I>    EUQH: Time for file (26) 4056ms
09.16 10:04:22+   47 [41E40] 10  M>    <  3 [437ms] CIMCacheManager::CreateCacheImage
09.16 10:04:22+    0 [41E40] 10  I>   EUQH: Time for file (44) 7114ms
09.16 10:04:22+   15 [418C0] 10  M>    >  3 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:22+    0 [418C0] 10  M>     >  4 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:22+   78 [41E40] 10  M>      >  5 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:22+   47 [41E40] 10  M>       >  6 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:26+ 3869 [418C0] 10  M>       <  6 [3994ms] PTPIP::LoadThumbnail
09.16 10:04:26+    0 [418C0] 10  I>          ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:26+    0 [418C0] 10  M>      <  5 [3994ms] PTPIImage::LoadFile
09.16 10:04:26+    0 [418C0] 10  I>     EUQH::Load(1) of P:\Images\Photos\2015\Apr\Canon PowerShot SX50 HS_0045.jpg with 4000 x 3000 (O: 4000 x 3000) in 3994ms
09.16 10:04:26+    0 [418C0] 10  M>      >  5 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:27+  437 [418C0] 10  M>      <  5 [437ms] CIMCacheManager::CreateCacheImage
09.16 10:04:27+    0 [418C0] 10  I>     EUQH: Time for file (27) 4462ms
09.16 10:04:27+   78 [418C0] 10  M>      >  5 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:27+    0 [418C0] 10  M>       >  6 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:30+ 3915 [418C0] 10  M>       <  6 [3915ms] PTPIP::LoadThumbnail
09.16 10:04:30+    0 [418C0] 10  I>          ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:30+    0 [418C0] 10  M>      <  5 [3915ms] PTPIImage::LoadFile
09.16 10:04:30+    0 [418C0] 10  I>     EUQH::Load(1) of P:\Images\Photos\2015\Apr\Canon PowerShot SX50 HS_0046.jpg with 4000 x 3000 (O: 4000 x 3000) in 3915ms
09.16 10:04:30+    0 [418C0] 10  M>      >  5 CIMCacheManager::CreateCacheImage  'IMCacheManager.cpp(882)'
09.16 10:04:31+  375 [418C0] 10  M>      <  5 [375ms] CIMCacheManager::CreateCacheImage
09.16 10:04:31+    0 [418C0] 10  I>     EUQH: Time for file (28) 4337ms
09.16 10:04:31+   78 [418C0] 10  M>      >  5 PTPIImage::LoadFile  'PTPIImage.cpp(202)'
09.16 10:04:31+    0 [418C0] 10  M>       >  6 PTPIP::LoadThumbnail  'PTPIP.cpp(2986)'
09.16 10:04:34+ 3135 [4251C] 10  I>       CIMCacheManager::UpdateStats in 0ms
09.16 10:04:34+    0 [41C08] 10  M>       <  6 [19531ms #sl] PTPIP::LoadThumbnail
09.16 10:04:34+    0 [41C08] 10  I>          ImageInfo: 'Format: JPEG File Interchange FormatColor Component Storage: 24 bits per pixelJFIF Version 1.01Embedded Color Profile: IEC 61966-2.1 Default RGB colour space - sRGB'
09.16 10:04:34+    0 [41C08] 10  M>      <  5 [19625ms #sl] PTPIImage::LoadFile
09.16 10:04:34+    0 [41C08] 10  I>     EUQH::Load(1) of P:\Images\Photos\2015\May\Canon PowerShot SX50 HS_0088.jpg with 4000 x 3000 (O: 4000 x 3000) in 19625ms
..................................
..................................
09.16 10:10:08+    0 [41E40] 50  M>  <  1 CIMEngine5::SetFile
09.16 10:10:08+    0 [41E40] 50  M>  >  1 CIMEngine5::SetFile  'IMEngine5.cpp(4964)'
09.16 10:10:08+    0 [41E40] 50  M>   >  2 CIMCatalog::UpdateFile  'catalog\imcatalog.cpp(1457)'
09.16 10:10:08+    0 [41E40] 50  M>   <  2 CIMCatalog::UpdateFile
09.16 10:10:08+    0 [41E40] 50  M>  <  1 CIMEngine5::SetFile
09.16 10:10:08+    0 [41E40] 50  M>  >  1 CIMEngine5::SetFile  'IMEngine5.cpp(4964)'
09.16 10:10:08+    0 [41E40] 50  M>   >  2 CIMCatalog::UpdateFile  'catalog\imcatalog.cpp(1457)'
09.16 10:10:08+    0 [41E40] 50  M>   <  2 CIMCatalog::UpdateFile
09.16 10:10:08+    0 [41E40] 50  M>  <  1 CIMEngine5::SetFile
09.16 10:10:08+    0 [41E40] 50  M>  >  1 CIMEngine5::SetFile  'IMEngine5.cpp(4964)'
09.16 10:10:08+    0 [41E40] 50  M>   >  2 CIMCatalog::UpdateFile  'catalog\imcatalog.cpp(1457)'
09.16 10:10:08+    0 [41E40] 50  M>   <  2 CIMCatalog::UpdateFile
09.16 10:10:08+    0 [41E40] 50  M>  <  1 CIMEngine5::SetFile
09.16 10:10:08+    0 [41E40] 10  I> FileHist Delegate: 20 of 20 events written in 0ms
09.16 10:10:08+    0 [41E40] 10  I> EUQH: Processed 20 files in 375432ms
..................
..................

Happy to attach a clear debug file if that would help...

114 images took

Jingo

#1
September 16, 2015, 04:23:54 PM
Well.. I think I just answered my own question... here is a log entry for writing a single keyword back to one image... took over 40 seconds... something wrong with this my drive config for sure.. need to move to Plan B I guess!

09.16 10:19:23+    0 [42710] 05  I>    ExifTool: Launching from 'C:\Program Files (x86)\photools.com\IMatch5\exiftool.exe', using IMatch config file 'C:\Program Files (x86)\photools.com\IMatch5\imatch_et.config' (C:\PROGRA~2\photools.com\IMatch5\IMATCH~1.CON)
09.16 10:19:23+  124 [42748] 10  I>    FileHist Delegate: 1 of 1 events written in 0ms
09.16 10:19:23+  203 [42710] 10  M>     >  4 PTETWrapper::ListExtensions  'PTETWrapper.cpp(1481)'
09.16 10:19:23+    0 [42710] 10  M>      >  5 PTETWrapper::ProcessRun  'PTETWrapper.cpp(3380)'
09.16 10:19:24+  359 [42710] 10  M>      <  5 [359ms] PTETWrapper::ProcessRun
09.16 10:19:24+    0 [42710] 10  M>     <  4 [359ms] PTETWrapper::ListExtensions
09.16 10:19:24+    0 [42710] 10  M>     >  4 PTETWrapper::ListExtensions  'PTETWrapper.cpp(1481)'
09.16 10:19:24+    0 [42710] 10  M>      >  5 PTETWrapper::ProcessRun  'PTETWrapper.cpp(3380)'
09.16 10:19:24+  109 [42710] 10  M>      <  5 [109ms] PTETWrapper::ProcessRun
09.16 10:19:24+    0 [42710] 10  M>     <  4 [109ms] PTETWrapper::ListExtensions
09.16 10:19:24+    0 [42710] 10  M>     >  4 PTETWrapper::ProcessRun  'PTETWrapper.cpp(3380)'
09.16 10:20:05+40654 [42710] 10  M>     <  4 [40654ms #sl] PTETWrapper::ProcessRun
09.16 10:20:05+    0 [42710] 10  M>    <  3 [41449ms #sl] PTETWrapper::Write
09.16 10:20:05+    0 [42710] 50  I>       PTMetabase::WriteBack successful for file [19] 'P:\Images\Photos\2015\Apr\Canon PowerShot SX50 HS_0037.jpg' in 41 s
09.16 10:20:05+    0 [42710] 50  M>    >  3 PTMetabase::Propagate  'PTMetabase.cpp(8090)'
09.16 10:20:05+    0 [42710] 50  M>    <  3 PTMetabase::Propagate
09.16 10:20:05+    0 [42710] 10  I>       PTMetabase::WriteBack for 1 files in 41449ms

Mario

#2
September 16, 2015, 04:39:40 PM
QuoteThe photo drive is running on my MAC machine on network with MACDRIVE running for access.

This is probably the worst case for anything related to read/write performance. On a Mac. Over a network...
-- Mario
IMatch Developer
Forum Administrator
http://www.photools.com  -  Contact & Support - Follow me on 𝕏 - Like photools.com on Facebook

Jingo

#3
September 17, 2015, 02:20:39 AM
Yes.. I know.. it worked pretty snazily in my last configuration (Parallels running Win7 on my MAC with mapped drives) but I guess that was still accessing local MAC drives however it looked inside the virtual machine.   I have since switched to 2 machines with a hardware KVM switch sharing dual monitors, mouse and keyboard.  Both the MAC and PC are now unique physical boxes and with a quick switch - I can have the best of both systems.  However, since my main photography and digital publishing system is my MAC - I was using a MAC internal drive via network share for my PC and IMatch - and thus the slowness....

Since playing with this today - I have now started an export of my images from LR on my MAC to a Win7 drive that is local to my PC and I created a new database to read the files from this local drive in IMatch.  The results are what we all expect... flying colors!   

Sorry for the false issue... I should have known it was something local to me!   Thx - Andy.

Print
Go Up Pages1
User actions