Timing writing back of meta data to a file

Started by rik, June 22, 2014, 03:16:10 PM

Previous topic - Next topic

rik

Is there a way to time the actions imatch is performing while writing meta data back to a file?
I have this situation that I want to write back meta data for a jpg file of size 3200 x 4300 and the log panel tells me it takes 1 minute for only one file.
Also, if I run a metadata template to copy one tag to another, this one also takes 1 minute to run.
I have Imatch version 5.1.3 in VirtualBox running in win7 on opensuse 13.1.

Thanks!

joel23

In the log file you should see something like
PTMetabase::WriteBack successful for file <file_name_here> in 0,6 s
and
PTMetabase::WriteBack for 1 files in 608ms
regards,
Joerg

rik

Thanks. ExifTool is very slow when writing outside of VirtualBox (that is, a network directory). See below. If I write in VirtualBox (that is, a local directory), writing is fast.
Any hints how I can improve this?
Thanks!

This is an exerpt of the logfile:

06.24 12:52:24+    0 [0FF8] 05  I>                  ExifTool: Launching from 'C:\Program Files\IMatch5\exiftool.exe', using IMatch config file 'C:\Program Files\IMatch5\imatch_et.config' (C:\PROGRA~1\IMatch5\IMATCH~1.CON)
06.24 12:52:25+  328 [0FF8] 10  M>                   > 18 PTETWrapper::ListExtensions  'PTETWrapper.cpp(1477)'
06.24 12:52:25+    0 [0FF8] 10  M>                    > 19 PTETWrapper::ProcessRun  'PTETWrapper.cpp(3166)'
06.24 12:52:25+  359 [0FF8] 10  M>                    < 19 [359ms] PTETWrapper::ProcessRun
06.24 12:52:25+    0 [0FF8] 10  M>                   < 18 [359ms] PTETWrapper::ListExtensions
06.24 12:52:25+    0 [0FF8] 10  M>                   > 18 PTETWrapper::ListExtensions  'PTETWrapper.cpp(1477)'
06.24 12:52:25+    0 [0FF8] 10  M>                    > 19 PTETWrapper::ProcessRun  'PTETWrapper.cpp(3166)'
06.24 12:52:25+  110 [0FF8] 10  M>                    < 19 [110ms] PTETWrapper::ProcessRun
06.24 12:52:25+    0 [0FF8] 10  M>                   < 18 [110ms] PTETWrapper::ListExtensions
06.24 12:52:25+    0 [0FF8] 50  M>                   > 18 PTMetabase::GetFileValues  'PTMetabase.cpp(8979)'
06.24 12:52:25+    0 [0FF8] 50  M>                   < 18 PTMetabase::GetFileValues
06.24 12:52:25+    0 [0FF8] 50  M>                   > 18 PTMetabase::GetFileValues  'PTMetabase.cpp(8979)'
06.24 12:52:25+    0 [0FF8] 50  M>                   < 18 PTMetabase::GetFileValues
06.24 12:52:25+    0 [0FF8] 50  M>                   > 18 PTMetabase::GetFileValues  'PTMetabase.cpp(8979)'
06.24 12:52:25+    0 [0FF8] 50  M>                   < 18 PTMetabase::GetFileValues
06.24 12:52:25+    0 [0FF8] 10  M>                   > 18 PTETWrapper::ProcessRun  'PTETWrapper.cpp(3166)'
06.24 12:54:35+130203 [0FF8] 10  M>                   < 18 [130203ms] PTETWrapper::ProcessRun
06.24 12:54:35+    0 [0FF8] 10  M>                  < 17 [131000ms] PTETWrapper::Write
06.24 12:54:35+    0 [0FF8] 50  I>                     PTMetabase::WriteBack successful for file [7] '\\HOSTNAME\data\tijdelijk\imatch-proef2\140609-Vuurol-Lage-Vuursche\vuurol-14.jpg' in 2 Minutes
06.24 12:54:35+    0 [0FF8] 50  M>                  > 17 PTMetabase::Propagate  'PTMetabase.cpp(12232)'
06.24 12:54:35+    0 [0FF8] 50  M>                  < 17 PTMetabase::Propagate
06.24 12:54:35+    0 [0FF8] 10  I>                     PTMetabase::WriteBack for 1 files in 131000ms
06.24 12:54:35+    0 [0FF8] 50  M>                  > 17 CIMEngine5::TouchFiles  'IMEngine5.cpp(4016)'

joel23

Quote from: rik on June 24, 2014, 10:01:35 PM
Thanks. ExifTool is very slow when writing outside of VirtualBox (that is, a network directory). See below. If I write in VirtualBox (that is, a local directory), writing is fast.
Any hints how I can improve this?
Thanks!
Sorry, not really sure what you are talking about. Is this an ordinary NAS-Device, or an Oracle VirtualBoX?
A bit more info eg. if "\\HOSTNAME\" is the same machine or another and where it's located (LAN, WAN) would be nice. What results (timing) do you get when pinging "HOSTNAME"? 
Have you ever tried to map/mount the device instead of using UNC-paths?
regards,
Joerg

Mario

Disk access from a virtualized Windows installation (Virtual Box, Virtual PC, VMWare) goes through many hoops an even has to use the network interfaces. This is many, many times slower than the "local" disk in the VirtualBox. Which is also a lot slower than any regular disk.
-- Mario
IMatch Developer
Forum Administrator
http://www.photools.com  -  Contact & Support - Follow me on 𝕏 - Like photools.com on Facebook

Jingo

This is interesting... I use Parallels to access IMatch from my Hackintosh Mavericks machine and haven't run into too many slow access points yet.  I was using VMware but it was VERY slow accessing my NTFS drives so I switched to Parallels and things are MUCH faster.  Not sure how or what causes the Exiftool to write back - but here is a snippet from an update to a DNG file stored outside the virtual drive (Rating, attribute, keyword, Title added):

06.25 07:28:44+    0 [0F38] 10  M>   >  2 PTMetabase::WriteBack  'PTMetabase.cpp(11391)'
06.25 07:28:44+    0 [0F38] 10  I>       1 files to write-back to
06.25 07:28:44+    0 [0F38] 10  M>    >  3 PTFileSystemMonitor::Enable  'PTFileSystemMonitor.cpp(756)'
06.25 07:28:44+    0 [0F38] 10  M>    <  3 PTFileSystemMonitor::Enable
06.25 07:28:44+    0 [0F38] 50  M>    >  3 CIMRelationManager::GetVersions  'IMRelationManager.cpp(1859)'
06.25 07:28:44+    0 [0F38] 50  M>    <  3 CIMRelationManager::GetVersions
06.25 07:28:44+    0 [0F38] 10  M>    >  3 PTMetabase::GetFileValues  'PTMetabase.cpp(9072)'
06.25 07:28:44+    0 [0F38] 10  M>    <  3 PTMetabase::GetFileValues
06.25 07:28:44+    0 [0F38] 50  M>    >  3 PTMetabase::GetFileValues  'PTMetabase.cpp(8979)'
06.25 07:28:44+    0 [0F38] 50  M>    <  3 PTMetabase::GetFileValues
06.25 07:28:44+    0 [0F38] 10  M>    >  3 PTETWrapper::Write  'PTETWrapper.cpp(2557)'
06.25 07:28:44+    0 [0F38] 50  M>     >  4 PTMetabase::GetFileValues  'PTMetabase.cpp(8979)'
06.25 07:28:44+    0 [0F38] 50  M>     <  4 PTMetabase::GetFileValues
06.25 07:28:44+    0 [0F38] 50  M>     >  4 PTMetabase::GetFileValues  'PTMetabase.cpp(8979)'
06.25 07:28:44+    0 [0F38] 50  M>     <  4 PTMetabase::GetFileValues
06.25 07:28:44+    0 [0F38] 50  M>     >  4 PTMetabase::GetFileValues  'PTMetabase.cpp(8979)'
06.25 07:28:44+    0 [0F38] 50  M>     <  4 PTMetabase::GetFileValues
06.25 07:28:44+    0 [0F38] 10  M>     >  4 PTETWrapper::ProcessRun  'PTETWrapper.cpp(3166)'
06.25 07:28:47+ 2184 [0F38] 10  M>     <  4 [2184ms] PTETWrapper::ProcessRun
06.25 07:28:47+    0 [0F38] 10  M>    <  3 [2184ms] PTETWrapper::Write
06.25 07:28:47+    0 [0F38] 50  I>       PTMetabase::WriteBack successful for file [301] '\\psf\Host\Volumes\Photos\Photos\2014\Jun\NIKON D7100_6474.dng' in 2 s
06.25 07:28:47+    0 [0F38] 50  M>    >  3 PTMetabase::Propagate  'PTMetabase.cpp(12232)'
06.25 07:28:47+    0 [0F38] 50  M>    <  3 PTMetabase::Propagate
06.25 07:28:47+    0 [0F38] 10  I>       PTMetabase::WriteBack for 1 files in 2184ms

Took 2 seconds to write out the data...

Just to note as well... importing 384 DNG files (from the same non-virtual drive) that are 30MB a piece took 11 minutes... not bad ... but think I might try the JPG export from LR to see if this speed things up dramatically and just go that route instead of the DNG Update...

Mario

-- Mario
IMatch Developer
Forum Administrator
http://www.photools.com  -  Contact & Support - Follow me on 𝕏 - Like photools.com on Facebook

Jingo

Quote from: Mario on June 25, 2014, 02:12:58 PM
That's quite quick.

It is... I haven't played with it too much yet but it seemed pretty good in terms of write access.  How do you feel 11 mins to import the 384 photos (1.1 GB) is in terms of speed?

To those interested, I'm running a Hackintosh i5 16GB memory - Mavericks running on 640 GB partition 7200 drive.  My image drive is currently NTFS 2 TB drive and I'm using Tuxera NTFS for access.  I am running Parallels 9 in convergence mode.  Dual boot with Win 7 on SSD drive.

I plan to move OSx over to a new SSD at some point down the road too...

Mario

11 minutes for only 390 images? Sounds slow, even when cache files are being generated and the WIC codec is slow etc.
Do you have the debug log file from that session?
-- Mario
IMatch Developer
Forum Administrator
http://www.photools.com  -  Contact & Support - Follow me on 𝕏 - Like photools.com on Facebook

Jingo

I have the log file but I don't think debug was enabled - I did see some "subdirectory errors" - not sure what those are...  I can remove these images and try a subset again with debug turned on if more info would be helpful.  I removed a ton of image names below to make the log file a bit easier to read... but all 384 images were listed.  Thx!



[attachment deleted by admin]

rik

Quote from: joel23 on June 24, 2014, 10:24:02 PM
Quote from: rik on June 24, 2014, 10:01:35 PM
Thanks. ExifTool is very slow when writing outside of VirtualBox (that is, a network directory). See below. If I write in VirtualBox (that is, a local directory), writing is fast.
Any hints how I can improve this?
Thanks!
Sorry, not really sure what you are talking about. Is this an ordinary NAS-Device, or an Oracle VirtualBoX?
A bit more info eg. if "\\HOSTNAME\" is the same machine or another and where it's located (LAN, WAN) would be nice. What results (timing) do you get when pinging "HOSTNAME"? 
Have you ever tried to map/mount the device instead of using UNC-paths?

It is oracle virtualbox.
HOSTNAME is the machine running virtualbox (so it is the same machine).
the ping results are comparable when i do it from another machine in the local network.
My 1st try was with a mapped drive (like q:), 2nd try with \\hostname, both took really long.

I know that using virtualbox takes longer to execute than local, but shouldn't be that long (other applications with a lot of file access just run fine).

Hope this helps a bit.
Thanks a lot.

lenmerkel

Instead of accessing the host folder from the guest via networking, have you tried defining a shared folder for your VM (VirtualBox > Settings > Shared Folders)? In VirtualBox, shared folders use a file system driver in the guest VM to emulate a network share, but without using networking protocols. The file system driver is provided by the VirtualBox Guest Additions, so you'll need to have them installed in the guest VM, but I'm guessing you have probably done that already. You should find a shared folder faster. For a Windows guest, if you define the shared folder as auto-mounted, the share will be assigned a drive letter whenever your guest starts up.
Over the hill, and enjoying the glide.

rik

Quote from: lenmerkel on June 25, 2014, 08:10:42 PM
Instead of accessing the host folder from the guest via networking, have you tried defining a shared folder for your VM (VirtualBox > Settings > Shared Folders)? In VirtualBox, shared folders use a file system driver in the guest VM to emulate a network share, but without using networking protocols. The file system driver is provided by the VirtualBox Guest Additions, so you'll need to have them installed in the guest VM, but I'm guessing you have probably done that already. You should find a shared folder faster. For a Windows guest, if you define the shared folder as auto-mounted, the share will be assigned a drive letter whenever your guest starts up.

Thanks for the tip, this is exactly what I have done, I mapped it to the q: as I wrote. You are right in guessing that I have installed the guest editions. Maybe it is something specific to exiftool, since that one takes so long?

Thanks again.

lenmerkel

Sounds like you have the VM set up just right. It does look like ExifTool's writing may be the slow factor. Sorry I couldn't help more.  ???
Over the hill, and enjoying the glide.

joel23

Quote from: rik on June 25, 2014, 07:02:40 PM
I know that using virtualbox takes longer to execute than local, but shouldn't be that long (other applications with a lot of file access just run fine).
Check if those two lines change something -> 12.3.7.
regards,
Joerg