Convert from dpx to tiff, slow on nfs mount
Posted: 2010-03-22T09:12:16-07:00
Hi,
The following command takes a long time (~13-19 seconds) to execute on an nfs mount:
Running the same command on a local file system is fine (~0.5 seconds)
I'm on Centos 5.3, 64 bits and I've downloaded the ImageMagick-6.6.0-8 and configured and installed with the following options:
I've tried to compile with and without threading and openmp
The same symptoms are shown in the 6.3.8 version in the default CentOS 5.3 repo.
Anybody know what could be going on here?
Debug output further down.
Thanks!
- Hans Joergen
Edit: Changed timing information, as it's varying..
Edit2: This only happens on tiffs, other formats like jpeg or png seems fine.
DEBUG OUTPUT
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Configure convert-6.6[6905]: utility.c/ExpandFilenames/871/Configure
Command line: convert-6.6 {2P0076_013.1461459.dpx} {-debug} {all} {-depth} {16} {output.tif}
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Read; pattern="2P0076_013.1461459.dpx" ...
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Blob convert-6.6[6905]: blob.c/OpenBlob/2416/Blob
read 3 magic header bytes
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Cache convert-6.6[6905]: cache.c/DestroyPixelCache/1601/Cache
destroy
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Configure convert-6.6[6905]: configure.c/GetConfigureOptions/564/Configure
Searching for configure file: "/home/hansj/.magick/magic.xml"
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Configure convert-6.6[6905]: configure.c/GetConfigureOptions/564/Configure
Searching for configure file: "magic.xml"
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Exception convert-6.6[6905]: configure.c/GetConfigureOptions/589/Exception
UnableToOpenConfigureFile `magic.xml'
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Coder; rights=Read; pattern="DPX" ...
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Read; pattern="2P0076_013.1461459.dpx" ...
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Blob convert-6.6[6905]: blob.c/OpenBlob/2416/Blob
read 3 magic header bytes
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Area: 12.75MB/12.75MB/16.746GB
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Memory: 12.75MB/12.16MiB/11.697GiB
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Cache convert-6.6[6905]: cache.c/OpenPixelCache/4096/Cache
open 2P0076_013.1461459.dpx[0] (heap memory, 2048x778 12.16MiB)
2010-03-22T17:08:43+01:00 0:00.210 0.200u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Coder; rights=Write; pattern="TIF" ...
2010-03-22T17:08:43+01:00 0:00.210 0.200u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Write; pattern="output.tif" ...
2010-03-22T17:08:43+01:00 0:00.220 0.200u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Write; pattern="output.tif" ...
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Area: 12.75MB/12.75MB/16.746GB
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Memory: 12.75MB/24.31MiB/11.697GiB
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Cache convert-6.6[6905]: cache.c/OpenPixelCache/4096/Cache
open output.tif[0] (heap memory, 2048x778 12.16MiB)
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Cache convert-6.6[6905]: cache.c/CloneMemoryToMemoryPixelCache/1315/Cache
memory => memory
2010-03-22T17:08:43+01:00 0:00.250 0.240u 6.6.0 Resource convert-6.6[6905]: resource.c/RelinquishMagickResource/801/Resource
Memory: 12.75MB/12.16MiB/11.697GiB
2010-03-22T17:09:02+01:00 0:19.070 0.320u 6.6.0 Cache convert-6.6[6905]: cache.c/DestroyPixelCache/1601/Cache
destroy output.tif[0]
2010-03-22T17:09:02+01:00 0:19.070 0.320u 6.6.0 Resource convert-6.6[6905]: resource.c/RelinquishMagickResource/801/Resource
Memory: 12.75MB/0B/11.697GiB
The following command takes a long time (~13-19 seconds) to execute on an nfs mount:
Code: Select all
convert -debug all inputimage.dpx -depth 16 outputimage.tif
I'm on Centos 5.3, 64 bits and I've downloaded the ImageMagick-6.6.0-8 and configured and installed with the following options:
Code: Select all
./configure --without-perl --disable-openmp --program-suffix=-6.6 --prefix=/net/sw/opt/ImageMagick-6.6.0-8/ --disable-installed
The same symptoms are shown in the 6.3.8 version in the default CentOS 5.3 repo.
Anybody know what could be going on here?
Debug output further down.
Thanks!
- Hans Joergen
Edit: Changed timing information, as it's varying..
Edit2: This only happens on tiffs, other formats like jpeg or png seems fine.
DEBUG OUTPUT
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Configure convert-6.6[6905]: utility.c/ExpandFilenames/871/Configure
Command line: convert-6.6 {2P0076_013.1461459.dpx} {-debug} {all} {-depth} {16} {output.tif}
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Read; pattern="2P0076_013.1461459.dpx" ...
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Blob convert-6.6[6905]: blob.c/OpenBlob/2416/Blob
read 3 magic header bytes
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Cache convert-6.6[6905]: cache.c/DestroyPixelCache/1601/Cache
destroy
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Configure convert-6.6[6905]: configure.c/GetConfigureOptions/564/Configure
Searching for configure file: "/home/hansj/.magick/magic.xml"
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Configure convert-6.6[6905]: configure.c/GetConfigureOptions/564/Configure
Searching for configure file: "magic.xml"
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Exception convert-6.6[6905]: configure.c/GetConfigureOptions/589/Exception
UnableToOpenConfigureFile `magic.xml'
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Coder; rights=Read; pattern="DPX" ...
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Read; pattern="2P0076_013.1461459.dpx" ...
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Blob convert-6.6[6905]: blob.c/OpenBlob/2416/Blob
read 3 magic header bytes
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Area: 12.75MB/12.75MB/16.746GB
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Memory: 12.75MB/12.16MiB/11.697GiB
2010-03-22T17:08:43+01:00 0:00.000 0.000u 6.6.0 Cache convert-6.6[6905]: cache.c/OpenPixelCache/4096/Cache
open 2P0076_013.1461459.dpx[0] (heap memory, 2048x778 12.16MiB)
2010-03-22T17:08:43+01:00 0:00.210 0.200u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Coder; rights=Write; pattern="TIF" ...
2010-03-22T17:08:43+01:00 0:00.210 0.200u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Write; pattern="output.tif" ...
2010-03-22T17:08:43+01:00 0:00.220 0.200u 6.6.0 Policy convert-6.6[6905]: policy.c/IsRightsAuthorized/485/Policy
Domain: Path; rights=Write; pattern="output.tif" ...
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Area: 12.75MB/12.75MB/16.746GB
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Resource convert-6.6[6905]: resource.c/AcquireMagickResource/262/Resource
Memory: 12.75MB/24.31MiB/11.697GiB
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Cache convert-6.6[6905]: cache.c/OpenPixelCache/4096/Cache
open output.tif[0] (heap memory, 2048x778 12.16MiB)
2010-03-22T17:08:43+01:00 0:00.240 0.220u 6.6.0 Cache convert-6.6[6905]: cache.c/CloneMemoryToMemoryPixelCache/1315/Cache
memory => memory
2010-03-22T17:08:43+01:00 0:00.250 0.240u 6.6.0 Resource convert-6.6[6905]: resource.c/RelinquishMagickResource/801/Resource
Memory: 12.75MB/12.16MiB/11.697GiB
2010-03-22T17:09:02+01:00 0:19.070 0.320u 6.6.0 Cache convert-6.6[6905]: cache.c/DestroyPixelCache/1601/Cache
destroy output.tif[0]
2010-03-22T17:09:02+01:00 0:19.070 0.320u 6.6.0 Resource convert-6.6[6905]: resource.c/RelinquishMagickResource/801/Resource
Memory: 12.75MB/0B/11.697GiB