Slow when trying to Convert EMF file of size 6.2MB
Posted: 2012-06-08T09:30:57-07:00
I am trying to convert an EMF file of size 6.2MB (376x322) to JPEG using Imagemagick 6.4.3v Q16. It takes almost 18minutes to do that. This is on 32bit Windows Server 2003.
(The other EMF files of size <100KB gets converted in fraction of seconds)
I have debugged the convert process (below is the log) to see that it stops while loading the image to the cache, and once the image is loaded it continues to convert with in no time. So seems like a cache-ing issue to me. Can anyone help me with why would it take 15-18 minutes to cache a 6MB file ?
My Resources (even though Memory limit is 5gb, Cache uses only 9MB of it).
File Area Memory Map Disk
------------------------------------------------
1536 7.499gb 5.6243gb 14.998gb 16eb
Also I would like to add that, when I try to run the same conversion second time while the first run is going on (since a while like a 4-5mins), this second run completes in no time. Do anyone know why that would be ?
convert.exe -verbose -debug all TestImage
s\image13.emf -filter Gaussian TestImages\image13_filter.jpg
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Configure convert.exe[6244]: utility.c/ExpandFilenames/808/Configure
Command line: convert.exe {-verbose} {-debug} {all} {TestImages\image13.emf} {-filter} {Gaussian} {TestImages\image13_filter.jpg}
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1114/Module Searching for module "EMF" using filename "IM_MOD_RL_EMF_.dll"
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Module convert.exe[6244]: module.c/GetMagickModulePath/522/Module Searching for coder module file "IM_MOD_RL_EMF_.dll" ...
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1622/Configure SOFTWARE\ImageMagick\6.4.3\Q:16
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1640/Configure CoderModulesPath
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1123/Module Opening module at path "c:\Program Files\ImageMagick-6.4.3-Q16\modules\coders\IM_MOD_RL_EMF_.dll"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1150/Module Method "RegisterEMFImage" in module "EMF" at address 67281B00
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1164/Module Method "UnregisterEMFImage" in module "EMF" at address 67281B90
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Blob convert.exe[6244]: blob.c/OpenBlob/2353/Blob read 3 magic header bytes
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Cache convert.exe[6244]: cache.c/DestroyCacheInfo/2207/Cache destroy
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1622/Configure SOFTWARE\ImageMagick\6.4.3\Q:16
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1640/Configure ConfigurePath
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "c:\Program iles\ImageMagick-6.4.3-Q16\config\magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "C:\Documents and Settings\gqwkrqa\.magick\magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "C:\Program Files\ImageMagick-6.4.3-Q16\magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: magic.c/LoadMagicList/682/Configure Loading magic map "c:\Program Files\ImageMagick-6.4.3-Q16\config\magic.xml" ...
2012-06-08T11:43:13-04:00 0:01 0.031u 6.4.3 Configure convert.exe[6244]: magic.c/LoadMagicList/682/Configure Loading magic map "magic.xml" ...
2012-06-08T11:43:13-04:00 0:01 0.047u 6.4.3 Resource convert.exe[6244]: resource.c/AcquireMagickResource/220/Resource Area: 838kb/838kb/7.499gb
2012-06-08T11:43:13-04:00 0:01 0.047u 6.4.3 Resource convert.exe[6244]: resource.c/AcquireMagickResource/220/Resource Memory: 838kb/838kb/5.6243gb
2012-06-08T11:43:13-04:00 0:01 0.047u 6.4.3 Cache convert.exe[6244]: cache.c/OpenCache/3569/Cache open TestImages\image13.emf[0] (anonymous memory, 354x303 838kb)
TestImages\image13.emf EMF 354x303 354x303+0+0 16-bit DirectClass 96.656u 2:40
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1114/Module Searching for module "JPEG" using filename "IM_MOD_RL_JPEG_.dll" 2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/GetMagickModulePath/522/Module Searching for coder module file "IM_MOD_RL_JPEG_.dll" ...
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1622/Configure SOFTWARE\ImageMagick\6.4.3\Q:16
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1640/Configure CoderModulesPath
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1123/Module Opening module at path "c:\Program Files\ImageMagick-6.4.3-Q16\modules\coders\IM_MOD_RL_JPEG_.dll"
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1150/Module Method "RegisterJPEGImage" in module "JPEG" at address 67485A70
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1164/Module Method "UnregisterJPEGImage" in module "JPEG" at address 67483D00
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1687/Coder Image resolution: 72,72
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Resource convert.exe[6244]: resource.c/AcquireMagickResource/220/Resource Memory: 838kb/1.637mb/5.6243gb
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Resource convert.exe[6244]: resource.c/RelinquishMagickResource/853/Resource Memory: 838kb/838kb/5.6243gb2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1733/Coder Interlace: non-progressive
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1748/Coder Quality: 0
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder Convert.exe[6244]: jpeg.c/WriteJPEGImage/1852/Coder Storage class: DirectClass
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1854/Coder Depth: 16 2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1860/Coder Number of colors: unspecified
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1862/Coder JPEG data precision: 8
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1916/Coder Image colorspace is RGB
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1918/Coder Sampling factors: 1x1,1x1,1x1 TestImages\image13.emf=>TestImagesimage13_filter.jpg EMF 354x303 354x303+0+0 16 -bit DirectClass 25.8kb 0.063u 0:01
2012-06-08T11:44:52-04:00 1:40 96.766u 6.4.3 Resource convert.exe[6244]: resource.c/RelinquishMagickResource/853/Resource Memory: 838kb/0b/5.6243gb 2012-06-08T11:44:52-04:00 1:40 96.766u 6.4.3 Cache convert.exe[6244]: cache.c/DestroyCacheInfo/2207/Cache destroy TestImages\image13.emf[0]
(The other EMF files of size <100KB gets converted in fraction of seconds)
I have debugged the convert process (below is the log) to see that it stops while loading the image to the cache, and once the image is loaded it continues to convert with in no time. So seems like a cache-ing issue to me. Can anyone help me with why would it take 15-18 minutes to cache a 6MB file ?
My Resources (even though Memory limit is 5gb, Cache uses only 9MB of it).
File Area Memory Map Disk
------------------------------------------------
1536 7.499gb 5.6243gb 14.998gb 16eb
Also I would like to add that, when I try to run the same conversion second time while the first run is going on (since a while like a 4-5mins), this second run completes in no time. Do anyone know why that would be ?
convert.exe -verbose -debug all TestImage
s\image13.emf -filter Gaussian TestImages\image13_filter.jpg
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Configure convert.exe[6244]: utility.c/ExpandFilenames/808/Configure
Command line: convert.exe {-verbose} {-debug} {all} {TestImages\image13.emf} {-filter} {Gaussian} {TestImages\image13_filter.jpg}
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1114/Module Searching for module "EMF" using filename "IM_MOD_RL_EMF_.dll"
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Module convert.exe[6244]: module.c/GetMagickModulePath/522/Module Searching for coder module file "IM_MOD_RL_EMF_.dll" ...
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1622/Configure SOFTWARE\ImageMagick\6.4.3\Q:16
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1640/Configure CoderModulesPath
2012-06-08T11:43:13-04:00 0:01 0.000u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1123/Module Opening module at path "c:\Program Files\ImageMagick-6.4.3-Q16\modules\coders\IM_MOD_RL_EMF_.dll"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1150/Module Method "RegisterEMFImage" in module "EMF" at address 67281B00
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1164/Module Method "UnregisterEMFImage" in module "EMF" at address 67281B90
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Blob convert.exe[6244]: blob.c/OpenBlob/2353/Blob read 3 magic header bytes
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Cache convert.exe[6244]: cache.c/DestroyCacheInfo/2207/Cache destroy
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1622/Configure SOFTWARE\ImageMagick\6.4.3\Q:16
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1640/Configure ConfigurePath
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "c:\Program iles\ImageMagick-6.4.3-Q16\config\magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "C:\Documents and Settings\gqwkrqa\.magick\magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "C:\Program Files\ImageMagick-6.4.3-Q16\magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: configure.c/GetConfigureOptions/528/Configure Searching for configure file: "magic.xml"
2012-06-08T11:43:13-04:00 0:01 0.016u 6.4.3 Configure convert.exe[6244]: magic.c/LoadMagicList/682/Configure Loading magic map "c:\Program Files\ImageMagick-6.4.3-Q16\config\magic.xml" ...
2012-06-08T11:43:13-04:00 0:01 0.031u 6.4.3 Configure convert.exe[6244]: magic.c/LoadMagicList/682/Configure Loading magic map "magic.xml" ...
2012-06-08T11:43:13-04:00 0:01 0.047u 6.4.3 Resource convert.exe[6244]: resource.c/AcquireMagickResource/220/Resource Area: 838kb/838kb/7.499gb
2012-06-08T11:43:13-04:00 0:01 0.047u 6.4.3 Resource convert.exe[6244]: resource.c/AcquireMagickResource/220/Resource Memory: 838kb/838kb/5.6243gb
2012-06-08T11:43:13-04:00 0:01 0.047u 6.4.3 Cache convert.exe[6244]: cache.c/OpenCache/3569/Cache open TestImages\image13.emf[0] (anonymous memory, 354x303 838kb)
TestImages\image13.emf EMF 354x303 354x303+0+0 16-bit DirectClass 96.656u 2:40
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1114/Module Searching for module "JPEG" using filename "IM_MOD_RL_JPEG_.dll" 2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/GetMagickModulePath/522/Module Searching for coder module file "IM_MOD_RL_JPEG_.dll" ...
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1622/Configure SOFTWARE\ImageMagick\6.4.3\Q:16
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Configure convert.exe[6244]: nt-base.c/NTRegistryKeyLookup/1640/Configure CoderModulesPath
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1123/Module Opening module at path "c:\Program Files\ImageMagick-6.4.3-Q16\modules\coders\IM_MOD_RL_JPEG_.dll"
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1150/Module Method "RegisterJPEGImage" in module "JPEG" at address 67485A70
2012-06-08T11:44:52-04:00 1:40 96.719u 6.4.3 Module convert.exe[6244]: module.c/OpenModule/1164/Module Method "UnregisterJPEGImage" in module "JPEG" at address 67483D00
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1687/Coder Image resolution: 72,72
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Resource convert.exe[6244]: resource.c/AcquireMagickResource/220/Resource Memory: 838kb/1.637mb/5.6243gb
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Resource convert.exe[6244]: resource.c/RelinquishMagickResource/853/Resource Memory: 838kb/838kb/5.6243gb2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1733/Coder Interlace: non-progressive
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1748/Coder Quality: 0
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder Convert.exe[6244]: jpeg.c/WriteJPEGImage/1852/Coder Storage class: DirectClass
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1854/Coder Depth: 16 2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1860/Coder Number of colors: unspecified
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1862/Coder JPEG data precision: 8
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1916/Coder Image colorspace is RGB
2012-06-08T11:44:52-04:00 1:40 96.734u 6.4.3 Coder convert.exe[6244]: jpeg.c/WriteJPEGImage/1918/Coder Sampling factors: 1x1,1x1,1x1 TestImages\image13.emf=>TestImagesimage13_filter.jpg EMF 354x303 354x303+0+0 16 -bit DirectClass 25.8kb 0.063u 0:01
2012-06-08T11:44:52-04:00 1:40 96.766u 6.4.3 Resource convert.exe[6244]: resource.c/RelinquishMagickResource/853/Resource Memory: 838kb/0b/5.6243gb 2012-06-08T11:44:52-04:00 1:40 96.766u 6.4.3 Cache convert.exe[6244]: cache.c/DestroyCacheInfo/2207/Cache destroy TestImages\image13.emf[0]