Page 1 of 2

Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-11T09:41:29-07:00
by m-wynn
I have a script for MPD that converts the album art to a 100x100 png file and displays it as a notification whenever I switch music tracks. After updating to ImageMagick 6.8.9.8-1, I noticed that this process was much slower, and made my computer unresponsive for a few seconds while it converted

The script itself says

Code: Select all

convert "$cover" -thumbnail $COVER_RESIZE -gravity "center" -background "$COVER_BACKGROUND" -extent $COVER_RESIZE "$TEMP_PATH"
And the actual running process would be:

Code: Select all

convert /path/to/cover.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
I played around with downgrading and upgrading, and found a huge difference between the time and CPU usage needed to convert a 500x500 jpg file to a 100x100 png.

Code: Select all

$ convert -version 
Version: ImageMagick 6.8.9-7 Q16 x86_64 2014-08-25 http://www.imagemagick.org

$ time convert /tmp/test.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
convert /tmp/test.jpg -thumbnail 100x100 -gravity center -background none     0.02s user 0.00s system 135% cpu 0.017 total
Then, upon updating.

Code: Select all

$ convert -version
Version: ImageMagick 6.8.9-8 Q16 x86_64 2014-10-09 http://www.imagemagick.org

$ time convert /tmp/test.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
convert /tmp/test.jpg -thumbnail 100x100 -gravity center -background none     9.85s user 0.12s system 376% cpu 2.650 total
Thanks in advance for looking into it.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-11T14:29:53-07:00
by glennrp
There was a change in thread-handling in JPEG between 6.8.9-7 and 6.8.9-8.
I don't see a performance difference between -7 and -8 on my Ubuntu 2-core platform.
What happens if you add "-limit thread 1" to the beginning of your command? i.e.,

Code: Select all

time convert -limit thread 1 /tmp/test.jpg ...

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-11T14:52:39-07:00
by m-wynn
That takes less CPU, but a bit more total time. Still nowhere near the 0.017s I got on the previous version.

Code: Select all

$ time convert /tmp/test.jpg -limit thread 1 -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
convert /tmp/test.jpg -limit thread 1 -thumbnail 100x100 -gravity center  non  5.48s user 0.63s system 111% cpu 5.502 total
I'm running Arch Linux on a i7-4510U CPU @ 2GHz, and kernel 3.16.5-1-ck, if that's any help.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-12T07:44:51-07:00
by glennrp
I still cannot reproduce your results. I'm testing with libjpeg 6.2 and 8.0. What libjpeg are you using
("convert -list format | grep JPEG" to find out)?

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-12T07:46:50-07:00
by magick
Try this command:
  • time convert -define jpeg:size 100x100 cover.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 mpdcover.png

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-12T11:11:26-07:00
by m-wynn
Version 6.8.9-7:

Code: Select all

time convert -define jpeg:size=100x100 /tmp/test.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
convert -define jpeg:size=100x100 /tmp/test.jpg -thumbnail 100x100 -gravity    0.01s user 0.00s system 113% cpu 0.011 total
And 6.8.9-8 is still much slower:

Code: Select all

time convert -define jpeg:size=100x100 /tmp/test.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
convert -define jpeg:size=100x100 /tmp/test.jpg -thumbnail 100x100 -gravity    9.96s user 0.55s system 365% cpu 2.879 total
As for my libjpeg version, it looks like I'm running 8.0.2

Code: Select all

convert -list format | grep JPEG                                                                                                            
           see part 5 which describes the image encoding (RLE, JPEG, JPEG-LS),
           and supplement 61 which adds JPEG-2000 encoding.
      JNG* PNG       rw-   JPEG Network Graphics
     JPEG* JPEG      rw-   Joint Photographic Experts Group JFIF format (80)
      JPG* JPEG      rw-   Joint Photographic Experts Group JFIF format (80)
    PJPEG* JPEG      rw-   Joint Photographic Experts Group JFIF format (80)

Code: Select all

$ sudo pacman -Qs libjpeg
local/lib32-libjpeg-turbo 1.3.1-1
    libjpeg derivative with accelerated baseline JPEG compression and decompression (32-bit)
local/libjpeg-turbo 1.3.1-1
    JPEG image codec with accelerated baseline compression and decompression
local/libjpeg6 6b1-2
    Library of JPEG support functions

I did some more testing and found that this isn't just JPEG to PNG files, but also PNG to PNG, JPEG to JPEG, and PNG to JPEG.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-12T11:33:49-07:00
by m-wynn
I did some stracing for fun.

Here's 6.8.9-7

Code: Select all

$ strace -c convert /tmp/test.jpg -limit thread 4 -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.000033           1        47           read
  0.00    0.000000           0         3           write
  0.00    0.000000           0        84        31 open
  0.00    0.000000           0        54           close
  0.00    0.000000           0        12         3 stat
  0.00    0.000000           0        52           fstat
  0.00    0.000000           0        10           lseek
  0.00    0.000000           0       117           mmap
  0.00    0.000000           0        72           mprotect
  0.00    0.000000           0        25           munmap
  0.00    0.000000           0         9           brk
  0.00    0.000000           0        11           rt_sigaction
  0.00    0.000000           0        19           rt_sigprocmask
  0.00    0.000000           0         4         1 access
  0.00    0.000000           0         1           clone
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         2           getdents
  0.00    0.000000           0         1           getcwd
  0.00    0.000000           0         1           readlink
  0.00    0.000000           0         2           getrlimit
  0.00    0.000000           0        18           times
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         8           futex
  0.00    0.000000           0         1           sched_getaffinity
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         2         1 openat
  0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00    0.000033                   559        36 total
And 6.8.9-8,

Code: Select all

$ strace -c convert /tmp/test.jpg -limit thread 4 -thumbnail 100x100 -gravity center -background none -extent 100x100 /tmp/mpdcover.png
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 56.99    0.001325          29        46           munmap
 43.01    0.001000          18        56           futex
  0.00    0.000000           0        50           read
  0.00    0.000000           0         4           write
  0.00    0.000000           0        89        31 open
  0.00    0.000000           0        59           close
  0.00    0.000000           0        23        13 stat
  0.00    0.000000           0        55           fstat
  0.00    0.000000           0        10           lseek
  0.00    0.000000           0       139           mmap
  0.00    0.000000           0        76           mprotect
  0.00    0.000000           0        12           brk
  0.00    0.000000           0        11           rt_sigaction
  0.00    0.000000           0        19           rt_sigprocmask
  0.00    0.000000           0         5         1 access
  0.00    0.000000           0         9           madvise
  0.00    0.000000           0         3           clone
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         2           getdents
  0.00    0.000000           0         1           getcwd
  0.00    0.000000           0         1           readlink
  0.00    0.000000           0         2           getrlimit
  0.00    0.000000           0        56           times
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         1           sched_getaffinity
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         2         1 openat
  0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00    0.002325                   735        46 total
I admit I have only a vague idea of what this means, but maybe you guys will. Additionally, adding -limit thread 1 doesn't do much aside from increase the usecs/call of munmap.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-12T17:18:04-07:00
by magick
Let's see if there are any differences in the configuration. Post the output for
  • convert -list configure
for 6.8.9-7 and 6.8.9-8. It looks like 6.8.9-8 is using memory-mapped anonymous memory which is slower than real-memory because it zeros the allocation. Perhaps the build configuration will account for this difference.

Next, run the command for 6.8.9-7 and 6.8.9-8 but add -debug cache at the beginning of the command line. It will let us know how the pixel cache is allocated. Post the results here.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-12T17:57:40-07:00
by m-wynn
Alright, here's the configuration, but I don't see any differences.

6.8.9-7

Code: Select all

$     convert -list configure

Path: /usr/lib/ImageMagick-6.8.9//config-Q16HDRI/configure.xml

Name           Value
-------------------------------------------------------------------------------
CC             gcc -std=gnu99 -std=gnu99
CFLAGS         -I/usr/include/lqr-1 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/include/freetype2 -I/usr/include/libpng16 -I/usr/include/harfbuzz -pthread -fopenmp -march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4 -Wall -march=x86-64 -fexceptions -pthread -DMAGICKCORE_HDRI_ENABLE=1 -DMAGICKCORE_QUANTUM_DEPTH=16
CODER_PATH     /usr/lib/ImageMagick-6.8.9/modules-Q16HDRI/coders
CONFIGURE      ./configure  '--prefix=/usr' '--sysconfdir=/etc' '--with-modules' '--enable-hdri' '--with-wmf' '--with-openexr' '--with-xml' '--with-lcms2' '--with-webp' '--with-gslib' '--with-gs-font-dir=/usr/share/fonts/Type1' '--with-perl' '--with-perl-options=INSTALLDIRS=vendor' '--with-lqr' '--with-rsvg' '--enable-opencl' '--with-openjp2' '--without-gvc' '--without-djvu' '--without-autotrace' '--without-jbig' '--without-fpx' '--without-dps' '--without-fftw' '--with-gcc-arch=x86-64' 'CFLAGS=-march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4' 'LDFLAGS=-Wl,-O1,--sort-common,--as-needed,-z,relro' 'CPPFLAGS=-D_FORTIFY_SOURCE=2' 'CXXFLAGS=-march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4'
CONFIGURE_PATH /etc/ImageMagick-6/
COPYRIGHT      Copyright (C) 1999-2014 ImageMagick Studio LLC
CPPFLAGS       -I/usr/include/ImageMagick-6
CXX            g++
CXXFLAGS       -march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4 -pthread
DEFS           -DHAVE_CONFIG_H
DELEGATES      bzlib mpeg fontconfig freetype gslib jng jpeg lcms lqr lzma openjp2 pango png ps rsvg tiff webp wmf x xml zlib
DISTCHECK_CONFIG_FLAGS 'CFLAGS=-march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4' 'CPPFLAGS=-D_FORTIFY_SOURCE=2' 'LDFLAGS=-Wl,-O1,--sort-common,--as-needed,-z,relro' --disable-deprecated --with-quantum-depth=16 --with-umem=no --with-autotrace=no --with-dps=no --with-djvu=no --with-fftw=no --with-fpx=no --with-fontpath= --with-gs-font-dir=/usr/share/fonts/Type1 --with-gvc=no
DOCUMENTATION_PATH /usr/share/doc/ImageMagick-6
EXEC-PREFIX    /usr
EXECUTABLE_PATH /usr/bin
FEATURES       DPC HDRI OpenCL OpenMP Modules
FILTER_PATH    /usr/lib/ImageMagick-6.8.9/modules-Q16HDRI/filters
HOST           x86_64-unknown-linux-gnu
INCLUDE_PATH   /usr/include/ImageMagick-6
LDFLAGS        -L/usr/lib -Wl,-O1,--sort-common,--as-needed,-z,relro
LIB_VERSION    0x689
LIB_VERSION_NUMBER 6,8,9,7
LIBRARY_PATH   /usr/lib/ImageMagick-6.8.9
LIBS           -llcms2 -lfreetype -llqr-1 -lglib-2.0 -lfontconfig -lfreetype -lXext -lX11 -lXt -llzma -lbz2 -lz -lltdl -lm -lgomp -lm
NAME           ImageMagick
PCFLAGS        -fopenmp -DMAGICKCORE_HDRI_ENABLE=1 -DMAGICKCORE_QUANTUM_DEPTH=16
PREFIX         /usr
QuantumDepth   16
RELEASE_DATE   2014-08-25
SHARE_PATH     /usr/share/ImageMagick-6
SHAREARCH_PATH /usr/lib/ImageMagick-6.8.9/config-Q16HDRI
SVN_REVISION   16331
TARGET_CPU     x86_64
TARGET_OS      linux-gnu
TARGET_VENDOR  unknown
VERSION        6.8.9
WEBSITE        http://www.imagemagick.org

Path: [built-in]

Name           Value
-------------------------------------------------------------------------------
FEATURES       OpenMP 
NAME           ImageMagick
QuantumDepth   16
And 6.8.9-8

Code: Select all

$     convert -list configure                                                                                                                  1 ↵

Path: /usr/lib/ImageMagick-6.8.9//config-Q16HDRI/configure.xml

Name           Value
-------------------------------------------------------------------------------
CC             gcc -std=gnu99 -std=gnu99
CFLAGS         -I/usr/include/lqr-1 -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include -I/usr/include/freetype2 -I/usr/include/libpng16 -I/usr/include/harfbuzz -pthread -fopenmp -march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4 -Wall -march=x86-64 -fexceptions -pthread -DMAGICKCORE_HDRI_ENABLE=1 -DMAGICKCORE_QUANTUM_DEPTH=16
CODER_PATH     /usr/lib/ImageMagick-6.8.9/modules-Q16HDRI/coders
CONFIGURE      ./configure  '--prefix=/usr' '--sysconfdir=/etc' '--with-modules' '--enable-hdri' '--with-wmf' '--with-openexr' '--with-xml' '--with-lcms2' '--with-webp' '--with-gslib' '--with-gs-font-dir=/usr/share/fonts/Type1' '--with-perl' '--with-perl-options=INSTALLDIRS=vendor' '--with-lqr' '--with-rsvg' '--enable-opencl' '--with-openjp2' '--without-gvc' '--without-djvu' '--without-autotrace' '--without-jbig' '--without-fpx' '--without-dps' '--without-fftw' '--with-gcc-arch=x86-64' 'CFLAGS=-march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4' 'LDFLAGS=-Wl,-O1,--sort-common,--as-needed,-z,relro' 'CPPFLAGS=-D_FORTIFY_SOURCE=2' 'CXXFLAGS=-march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4'
CONFIGURE_PATH /etc/ImageMagick-6/
COPYRIGHT      Copyright (C) 1999-2014 ImageMagick Studio LLC
CPPFLAGS       -I/usr/include/ImageMagick-6
CXX            g++
CXXFLAGS       -march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4 -pthread
DEFS           -DHAVE_CONFIG_H
DELEGATES      bzlib mpeg fontconfig freetype gslib jng jpeg lcms lqr lzma openjp2 pango png ps rsvg tiff webp wmf x xml zlib
DISTCHECK_CONFIG_FLAGS 'CFLAGS=-march=x86-64 -mtune=generic -O2 -pipe -fstack-protector-strong --param=ssp-buffer-size=4' 'CPPFLAGS=-D_FORTIFY_SOURCE=2' 'LDFLAGS=-Wl,-O1,--sort-common,--as-needed,-z,relro' --disable-deprecated --with-quantum-depth=16 --with-umem=no --with-autotrace=no --with-dps=no --with-fftw=no --with-fpx=no --with-djvu=no --with-fontpath= --with-gs-font-dir=/usr/share/fonts/Type1 --with-gvc=no
DOCUMENTATION_PATH /usr/share/doc/ImageMagick-6
EXEC-PREFIX    /usr
EXECUTABLE_PATH /usr/bin
FEATURES       DPC HDRI OpenCL OpenMP Modules
FILTER_PATH    /usr/lib/ImageMagick-6.8.9/modules-Q16HDRI/filters
HOST           x86_64-unknown-linux-gnu
INCLUDE_PATH   /usr/include/ImageMagick-6
LDFLAGS        -L/usr/lib -Wl,-O1,--sort-common,--as-needed,-z,relro
LIB_VERSION    0x689
LIB_VERSION_NUMBER 6,8,9,8
LIBRARY_PATH   /usr/lib/ImageMagick-6.8.9
LIBS           -llcms2 -lfreetype -llqr-1 -lglib-2.0 -lfontconfig -lfreetype -lXext -lX11 -lXt -llzma -lbz2 -lz -lltdl -lm -lgomp -lm
NAME           ImageMagick
PCFLAGS        -fopenmp -DMAGICKCORE_HDRI_ENABLE=1 -DMAGICKCORE_QUANTUM_DEPTH=16
PREFIX         /usr
QuantumDepth   16
RELEASE_DATE   2014-10-09
SHARE_PATH     /usr/share/ImageMagick-6
SHAREARCH_PATH /usr/lib/ImageMagick-6.8.9/config-Q16HDRI
SVN_REVISION   16502
TARGET_CPU     x86_64
TARGET_OS      linux-gnu
TARGET_VENDOR  unknown
VERSION        6.8.9
WEBSITE        http://www.imagemagick.org

Path: [built-in]

Name           Value
-------------------------------------------------------------------------------
FEATURES       OpenMP 
NAME           ImageMagick
QuantumDepth   16

Alright, -debug cache added. The output is fairly big, but the differences aren't hard to spot.

6.8.9-7
https://dl.dropboxusercontent.com/u/65012288/07.txt

and 6.8.9-8
https://dl.dropboxusercontent.com/u/65012288/08.txt

Hope that helps.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-13T07:58:22-07:00
by magick
The problem is that 6.8.9-8 is asking for a super-sampled image @ 2048x1536, whereas, our 6.8.9-8 asks for an image size of 500x500 as does your 6.8.9-7. Its starting to look like a compiler bug, we'll see. Edit magick/resize.c/ThumbnailImage()/3770. Add a debugging statement just before
  • printf("%ux%u\n",SampleFactor*columns,SampleFactor*rows);
    sample_image=SampleImage(image,SampleFactor*columns,SampleFactor*rows,
    exception);
    if (sample_image == (Image *) NULL)
    return((Image *) NULL);
    printf("%ux%u\n",sample_image->columns,sample_image->rows);
Does it return 500x500?

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-13T11:30:05-07:00
by m-wynn
Yes, it does return 500x500.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-13T13:11:19-07:00
by magick
We're clueless then. The pixel cache debugging suggests an image that is 2048x1536 is created. A larger image would account for why the processing time increased. However, we cannot reproduce the problem. Our debugging shows that the pixel cache creates a 500x500 pixel image as expected.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-13T14:06:48-07:00
by m-wynn
So odd.
I tested on another Arch Linux machine, and got the same results.

And from what you can tell, there's nothing in this PKGBUILD that would be leading to this issue? Maybe it's an Arch bug, though it doesn't look like the PKGBUILD changed between releases, other than the version number and sha1sums.

https://projects.archlinux.org/svntogit ... magemagick

I diffed and there's no difference between a direct download and the sunet.se mirror, and it doesn't look like the perl patch has anything to do with it.

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-13T15:19:54-07:00
by fmw42
I tested on my Mac OSX Snow Leopard with IM 6.8.9.8 and 6.8.9.7 using one thread with the following image and find no significant difference.

http://en.wikipedia.org/wiki/Grand_Teto ... tetons.jpg

It is 1600x1195

Code: Select all

time convert barns_grand_tetons.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 barn_test6898.jpg
real 0m0.361s
user 0m0.102s
sys 0m0.030s

Code: Select all

time im6897 convert barns_grand_tetons.jpg -thumbnail 100x100 -gravity center -background none -extent 100x100 barn_test6897.jpg
real 0m0.381s
user 0m0.119s
sys 0m0.052s



Version: ImageMagick 6.8.9-8 Q16 x86_64 2014-09-28 http://www.imagemagick.org
Copyright: Copyright (C) 1999-2014 ImageMagick Studio LLC
Features: DPC Modules
Delegates: bzlib cairo fftw fontconfig freetype gslib jbig jng jp2 jpeg lcms lqr ltdl lzma openexr png ps rsvg tiff webp x xml zlib


Version: ImageMagick 6.8.9-7 Q16 x86_64 2014-08-27 http://www.imagemagick.org
Copyright: Copyright (C) 1999-2014 ImageMagick Studio LLC
Features: DPC Modules
Delegates: bzlib cairo fftw fontconfig freetype gslib jbig jng jp2 jpeg lcms lqr ltdl lzma openexr png ps rsvg tiff webp x xml zlib

Re: Slowness in converting as of imagemagick 6.8.9-8

Posted: 2014-10-17T14:05:43-07:00
by anatolik
Hi I am an Linux Arch developer and I am trying to look at this issue as well.

There are no any Arch package changes between 6.8.9-7 and 6.8.9-8, it was just a version bump. To eliminate recent compiler/glib changes I tried to re-compile Arch packages for both versions and the regression still exists. This still might be a compiler/glib/... bug but it was triggered by 6.8.9-8 IM release somehow.

What we've found if that majority of time is spent in glibc __memcpy_avx_unaligned() function. If we test on recent hardware. People who has hardware without AVX support (e.g. Intel Atom) say that they do not see any regression in the latest version.