Converting page of TIFF takes much longer on virtual server
Posted: 2012-11-15T13:06:35-07:00
We are converting single pages of a multi-page TIFF to JPEG using ImageMagick-6.8.0-2-Q16-windows-x64. A typical conversion takes less than a second on our test (physical) servers and indeed on my laptop. On a production server, which is higher spec but virtual, a typical conversion takes around 5 seconds.
Interestingly, on the virtual server the first page image.tif[0] converts pretty quickly (the speed is comparable to on my laptop) but the time to convert gets progressively slower as the page number increases. So image.tif[20] takes much longer. I'm guessing that this is because IM needs to read in more of the TIFF as the page number increases and that, for some reason, on the virtual server this process is much slower.
My initial thought was that this is because the disk access on the virtual server is slower. I tried testing locally by moving the TIFF to a network drive and converting it from there using my laptop. This is still much faster than the virtual server, so I don't think the problem is with reading the TIFF into memory. I wondered if the issue was because of slower disk access affecting IM's disk cache but as far as I can see from the debug output below only the heap cache is used.
Can anyone explain this performance difference? Is there any way to improve the performance on the virtual server? I don't suppose there is a way to get IM to 'jump' to the right sub-file (i.e. page) within the TIFF without processing the ones before it?
This is the output when running the convert command with the -debug cache option, i.e.
convert -debug cache image.tif[20] test.jpg
Interestingly, on the virtual server the first page image.tif[0] converts pretty quickly (the speed is comparable to on my laptop) but the time to convert gets progressively slower as the page number increases. So image.tif[20] takes much longer. I'm guessing that this is because IM needs to read in more of the TIFF as the page number increases and that, for some reason, on the virtual server this process is much slower.
My initial thought was that this is because the disk access on the virtual server is slower. I tried testing locally by moving the TIFF to a network drive and converting it from there using my laptop. This is still much faster than the virtual server, so I don't think the problem is with reading the TIFF into memory. I wondered if the issue was because of slower disk access affecting IM's disk cache but as far as I can see from the debug output below only the heap cache is used.
Can anyone explain this performance difference? Is there any way to improve the performance on the virtual server? I don't suppose there is a way to get IM to 'jump' to the right sub-file (i.e. page) within the TIFF without processing the ones before it?
This is the output when running the convert command with the -debug cache option, i.e.
convert -debug cache image.tif[20] test.jpg
Code: Select all
2012-11-15T11:36:21+00:00 0:00.032 0.016u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:21+00:00 0:00.047 0.031u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:21+00:00 0:00.094 0.078u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[20] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:21+00:00 0:00.188 0.172u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[21] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:21+00:00 0:00.266 0.250u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[22] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:21+00:00 0:00.360 0.344u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[23] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:00.485 0.469u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[24] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:00.578 0.563u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[25] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:00.672 0.656u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[26] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:00.782 0.766u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[27] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:00.891 0.875u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[28] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:01.032 1.016u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[29] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:01.172 1.156u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[30] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:22+00:00 0:01.282 1.266u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[31] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:01.407 1.391u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[32] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:01.500 1.484u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[33] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:01.578 1.563u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[34] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:01.672 1.656u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[35] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:01.782 1.766u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[36] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:01.875 1.859u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[37] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:01.969 1.953u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[38] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:02.063 2.047u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[39] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:02.172 2.156u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[40] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:02.250 2.234u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[41] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:23+00:00 0:02.344 2.328u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[42] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:02.438 2.422u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[43] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:02.547 2.531u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[44] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:02.641 2.625u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[45] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:02.750 2.734u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[46] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:02.844 2.828u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[47] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:02.922 2.906u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[48] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:03.016 3.000u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[49] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:03.141 3.125u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[50] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:03.235 3.219u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[51] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:24+00:00 0:03.328 3.313u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[52] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:25+00:00 0:03.422 3.406u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[53] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:25+00:00 0:03.532 3.516u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[54] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:25+00:00 0:03.625 3.609u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache
image.tif[55] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:25+00:00 0:03.719 3.703u 6.8.0 Cache convert.exe[4668]: cache.c/OpenPixelCache/4053/Cache image.tif[56] (heap memory, 793x1122 6.788MiB) 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy 2012-11-15T11:36:25+00:00 0:03.813 3.797u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[21] 2012-11-15T11:36:25+00:00 0:03.828 3.813u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[22] 2012-11-15T11:36:25+00:00 0:03.828 3.813u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[23] 2012-11-15T11:36:25+00:00 0:03.844 3.828u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[24] 2012-11-15T11:36:25+00:00 0:03.860 3.844u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[25] 2012-11-15T11:36:25+00:00 0:03.860 3.844u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[26] 2012-11-15T11:36:25+00:00 0:03.875 3.859u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[27] 2012-11-15T11:36:25+00:00 0:03.891 3.875u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[28] 2012-11-15T11:36:25+00:00 0:03.891 3.875u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[29] 2012-11-15T11:36:25+00:00 0:03.907 3.891u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[30] 2012-11-15T11:36:25+00:00 0:03.907 3.891u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[31] 2012-11-15T11:36:25+00:00 0:03.922 3.906u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[32] 2012-11-15T11:36:25+00:00 0:03.938 3.922u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[33] 2012-11-15T11:36:25+00:00 0:03.938 3.922u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[34] 2012-11-15T11:36:25+00:00 0:03.953 3.938u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[35] 2012-11-15T11:36:25+00:00 0:03.953 3.938u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[36] 2012-11-15T11:36:25+00:00 0:03.969 3.953u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[37] 2012-11-15T11:36:25+00:00 0:03.985 3.969u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[38] 2012-11-15T11:36:25+00:00 0:03.985 3.969u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[39] 2012-11-15T11:36:25+00:00 0:04.000 3.984u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[40] 2012-11-15T11:36:25+00:00 0:04.000 3.984u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[41] 2012-11-15T11:36:25+00:00 0:04.016 4.000u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[42] 2012-11-15T11:36:25+00:00 0:04.016 4.000u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[43] 2012-11-15T11:36:25+00:00 0:04.032 4.016u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[44] 2012-11-15T11:36:25+00:00 0:04.047 4.031u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[45] 2012-11-15T11:36:25+00:00 0:04.047 4.031u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[46] 2012-11-15T11:36:25+00:00 0:04.063 4.047u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[47] 2012-11-15T11:36:25+00:00 0:04.063 4.047u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[48] 2012-11-15T11:36:25+00:00 0:04.078 4.063u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[49] 2012-11-15T11:36:25+00:00 0:04.078 4.063u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[50] 2012-11-15T11:36:25+00:00 0:04.094 4.078u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[51] 2012-11-15T11:36:25+00:00 0:04.110 4.094u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[52] 2012-11-15T11:36:25+00:00 0:04.110 4.094u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[53] 2012-11-15T11:36:25+00:00 0:04.125 4.109u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[54] 2012-11-15T11:36:25+00:00 0:04.125 4.109u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[55] 2012-11-15T11:36:25+00:00 0:04.141 4.125u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[56] 2012-11-15T11:36:25+00:00 0:04.188 4.172u 6.8.0 Cache convert.exe[4668]: cache.c/DestroyPixelCache/1449/Cache destroy image.tif[20] convert.exe: ASCII value for tag "DocumentName" contains null byte in value; value incorrectly truncated during reading due to implementation limitations. `TIFFFetchNormalTag' @ warning/tiff.c/TIFFWarnings/824.