Multi Process Contention?

[h1d3m3]

I am running ImageMagick under RedHat Enterprise, executed by a java process and am running into a odd performance issue.

I wrote a java test that reads an image, then spawns a thread with the image content. That thread does an identify, and then a -resize 111x111 on the image. All identify and convert commands are executed through carefully constructed exec() calls using only the stdin (to stream the image to "convert -") and stdout (to stream the results back from convert to the java thread). There is no file IO on the java side other than the initial read of the image (once).

This works great under light loads, but as soon as the thread count goes up, the load increases almost exponentially and throughput goes way down....for example:

1 thread running 200 times : Average call time : 65ms, Total completion time: 13076ms (not too bad)
2 threads running 200 times : Average call time : 326ms, Total completion time: 32681ms (much slower!)
4 threads running 200 times : Average call time: 806ms, Total completion time: 40374ms
8 threads running 200 times :Average call time: 1952ms, Total completion time: 49108ms

So from the numbers above, it looks like processing requests serially gives us the best performance.....We did not expect this. It would seem that each convert process is possibly contending for some (common?) resource and slowing down every other convert process. The system we are running on has 32GB and has 8 cores....so I don't think it's CPU or memory.....but I'm not 100% sure overall.

Thanks for any help / ideas. (we cannot use JAI/Java2D and JMagick is too unstable). Let me know if any other info might be helpful.

Alan.

Below are some details if they are helpful.
- ImageMagick-6.5.4-6 (and we tried 6.4.1 as well)
- Java version 1.6.0_14-b08
- Red Hat Enterprise Linux Server release 5.3 (Tikanga)
- The photo we're converting is JPEG 640x480 640x480+0+0 8-bit DirectClass 61kb
- The convert command being called from java is "convert -quiet - -resize 111x111 -"
- We compiled ImageMagick with : ./configure --enable-shared --enable-static --disable-ltdl-install --disable-hdri --with-dps --with-bzlib --with-jpeg --with-png --with-tiff --with-zlib --with-modules --with-xml --with-x --without-perl --without-fpx --with-gslib --without-jbig --without-jp2 --without-lcms --without-wmf --without-gvc --without-rsvg

[magick]

Try disabling ImageMagick's internal threading. Add --disable-openmp to the configure command and reinstall and rerun your performance tests.

Are you calling the ImageMagick command line utilities? The overhead of starting a shell and ImageMagick reading its configuration files are pretty significant. Using a dynamically loadable API is recommend (e.g. JMagick, IMagick, PerlMagick, etc).

If you are creating thumbnails, add -size 111x111 before your image name. If the image is JPEG, it can speed up the resize significantly.

[h1d3m3]

Wow. What a difference (with --disable-openmp)

1 thread running 200 times : Average call time : 73ms, Total completion time: 14638ms
2 threads running 200 times : Average call time : 85ms, Total completion time: 8643ms
4 threads running 200 times : Average call time: 94ms, Total completion time: 4780ms
8 threads running 200 times :Average call time: 98ms, Total completion time: 2500ms

now that is what we expected.....but can you explain why turning off openmp (threading?) would produce such an effect? Were there too many threads per instance before?

[magick]

Enabling OpenMP for most algorithms creates 8 threads (1 per core). If your process creates 8 threads that's a total of 64 threads and that is a whole lot of contention and possible misuse of your processor cache.

[h1d3m3]

That makes sense.

For the record, this behaviour does not occur across all versions of Redhat. For the previous (slow) results above, with --enable-openmp and the very high load average, it was run on:

2.6.18-128.2.1.el5 #1 SMP Wed Jul 8 11:54:47 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux
Target: x86_64-redhat-linux
Configured with: ../configure --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --enable-shared --enable-threads=posix --enable-checking=release --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-libgcj-multifile --enable-languages=c,c++,objc,obj-c++,java,fortran,ada --enable-java-awt=gtk --disable-dssi --enable-plugin --with-java-home=/usr/lib/jvm/java-1.4.2-gcj-1.4.2.0/jre --with-cpu=generic --host=x86_64-redhat-linux
Thread model: posix
gcc version 4.1.2 20080704 (Red Hat 4.1.2-44)

and we just tested it on:

2.6.18-92.1.18.el5 #1 SMP Wed Nov 5 09:00:19 EST 2008 x86_64 x86_64 x86_64 GNU/Linux
Target: x86_64-redhat-linux
Configured with: ../configure --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --enable-shared --enable-threads=posix --enable-checking=release --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-libgcj-multifile --enable-languages=c,c++,objc,obj-c++,java,fortran,ada --enable-java-awt=gtk --disable-dssi --enable-plugin --with-java-home=/usr/lib/jvm/java-1.4.2-gcj-1.4.2.0/jre --with-cpu=generic --host=x86_64-redhat-linux
Thread model: posix
gcc version 4.1.2 20071124 (Red Hat 4.1.2-42)

with the same ImageMagick config settings..., which had OPENMP_CFLAGS='-fopenmp' OPENMP_CXXFLAGS='-fopenmp') The results were more like the --disable-openmp results!

In other words, our older systems (with openmp enabled) didn't show the same problem as the newer systems even with the same IM config settings.

Go figure.

[magick]

We suspect that OpenMP is still maturing. We have seen the same behavior even on the same release of the OS. We have two different systems with Centos 5.3 and on one system ImageMagick runs about 2-3 times faster and on the other system it runs 2-3 times slower (when OpenMP is enabled).

[dognose]

I am having the same problem. ( viewtopic.php?f=1&t=14051 )

It's not just 5.3 Centos, it's new installs of IM on older versions as well.. I think.
I tried reinstalling 5.2 centos, then installing IM and the required associated packages, and still had the problem.

I'd love to trace it down to what update has caused this problem, but I don't think it can just be blamed on Centos.

I'm at a loss of what to look into, any hints?

Unfortunately, disabling openmp is not a solution for me as most things now have an 8x slowdown.

[magick]

We need to reproduce a problem before we can offer insight or a solution. How can we set up a test case that shows ImageMagick is slowing down for you? If we replicate the slow down we can offer a solution on either why it slowed down or perhaps a patch that will fix the slowdown.

[dognose]

fyi: downgrading the libgomp package has seem to rectify the problem.

Was using 4.3.2-7.el5
now using 4.1.2-42.el5

not sure what they change along the way, but it wasn't good for im.

going from 8 to 64 threads should not have that detrimental effect.

[h1d3m3]

fyi: downgrading the libgomp package has seem to rectify the problem.

Was using 4.3.2-7.el5
now using 4.1.2-42.el5

not sure what they change along the way, but it wasn't good for im.

going from 8 to 64 threads should not have that detrimental effect.

I can confirm that this version change (to libgomp-4.3.2-7.el5) did happen on the systems where multi-instance IM performance was severely affected.

[thomers]

i had the same problem, on RHEL5 - even only 2 convert processes stalled the CPU at 99%.

recompiled with --disable-openmp, no problem any longer.

i wrote a short blog post about it (mainly so i remember it myself ).

cheers,
thomers

[aaronmefford]

Just confirmed a very similar issue using PerlMagick. Two simultaneous cgi calls which each generated an image worked fine under libgomp 4.1.2-14.el5 completing in 6-8 seconds. On a box running libgomp-4.4.0-6.el5 it falls apart, the time jumps 10x to complete the 2 simultaneous calls 60-80 seconds.

[anthony]

[quote="magick"Are you calling the ImageMagick command line utilities? The overhead of starting a shell and ImageMagick reading its configuration files are pretty significant.[/quote]

One of the goals of the IMv7 CLI redevelopment is the ability to stream operations to a single background Imagemagick. This will mean that a shell, java, PHP script can run one instance of IM (threaded or otherwise) and use that one instance to hold and process images in memory without needing multiple commands. It will provide an alternative demon-like method to using API's or multiple CLI commands. It is basically a programming technique known as 'co-processing'.

Information on how this is expected to work is given in IM examples, Development and Bugs area
http://www.imagemagick.org/Usage/bugs/I ... ipting.txt

Comments welcome.

I have started work on this but the initial part (modifying how IM processes command line options, and its handling of global settings) will take some time to achieve.