6.3.9 performance regession?
-
paraplegic
6.3.9 performance regession?
I'm just playing with the Wand api, and I noticed that a new version came out, so I compiled and linked it (on FreeBSD 6.2), and noticed a considerable performance degradation. Has anyone else confirmed this??
Re: 6.3.9 performance regession?
Without a specfic example and timing data we cannot help you. If you can show a timing degradation that we can reproduce, we will either account for the difference, suggest a workaround, or apply a patch to restore the previous timing results.
-
paraplegic
Re: 6.3.9 performance regession?
As requested, the timings, on mel.
Mel uname -a's as:
FreeBSD mel.controlq.com 6.2-RELEASE FreeBSD 6.2-RELEASE #1: Thu May 17 12:24:25 EDT 2007 rob@mel.controlq.com:/usr/src/sys/i386/compile/mel i386
I display the image on the same machine as I generate it, to take the X11 over the wire out of the equation
but timings are significant.
mel:
6.3.8 -
7.59 real 6.04 user 0.20 sys
7.47 real 6.08 user 0.17 sys
7.48 real 6.06 user 0.20 sys
mel:
6.3.9 - 53.08 real 48.54 user 0.37 sys
51.47 real 48.59 user 0.23 sys
51.67 real 48.66 user 0.22 sys
Q_Main is the routine I'm running, and library routines are pasted below for
reference. The Do( pic ...) macros simply invoke the im_XXXX( obj, args ... ),
So basically:
im_getFile: read file into a blob, then copy over to a wand in my
struct (i keep both a blob and a wand).
im_reScale: MagickScaleImage()
guiSetObjVar writes the Blob to a TK image (displays it)
im_GetProperties ->MagickGetImageProperties
im_GetOptions -> MagickGetOptions
Pretty straighforward ... sample code is below, and I used the Bourne shell time command
to provide the data above ...
int Q_Main( Tcl_Interp *interp ) {
Img_t *pic ;
long w ;
Lst_t *x ;
pic = New( Photo ) ;
Do( pic, GetFile, "/u0/Archive/20060730/A/img_0100.jpg" ) ;
printf( "::: Original Image is %ld x %ld (%ld bits deep) %ld bytes.\n",
Do( pic, Width), Do( pic,Height), Do( pic, Depth ), pic ->img ->size ) ;
w = Do( pic, Width ) ;
printf( "::: WIDTH = %ld\n", w ) ;
if( w > (long) 2048 ){
Do( pic, reScale, (double) .2 ) ;
}
guiSetObjVar( "imgX", 0, pic ->img ) ;
printf( "::: Resized Image is %ld x %ld (%ld bits deep) %ld bytes.\n",
Do( pic, Width), Do( pic,Height), Do( pic, Depth ), pic ->img ->size ) ;
printf( "::: Image description:\n\t%s\n", Do( pic, Describe ) ) ;
x = Do( pic, GetProfiles, "*" ) ;
if( x ){
printf( "::: Image Profiles:\n" ) ;
Do( x, Dump, 1 ) ;
Do( x, Destroy ) ;
}
x = Do( pic, GetProperties, 0, "*" ) ;
if( x ){
printf( "::: Image Properties:\n" ) ;
Do( x, Dump, 1 ) ;
Do( x, Destroy ) ;
}
x = Do( pic, GetOptions, 0, "*" ) ;
if( x ){
printf( "::: Image Options:\n" ) ;
Do( x, Dump, 1 ) ;
Do( x, Destroy ) ;
}
printf( "::: orient:\n\t%s\n", Do( pic, GetProperty, "exif:Orientation" ) ) ;
Exec_Tcl( code ) ;
Tk_MainLoop() ;
return( TCL_OK ) ;
}
Img_t *im_GetFile( Img_t *ob, char *path ){
if( ob ->img ){
destroyBlob( ob ->img ) ;
}
ob ->img = getFile( path ) ;
if( !ob ->wand ){
ob ->wand = NewMagickWand() ;
}
ClearMagickWand( ob ->wand ) ;
MagickReadImageBlob( ob ->wand, ob ->img ->buf, ob ->img ->actual ) ;
MagickSetFilename( ob ->wand, ob ->img ->path ) ;
return( ob ) ;
}
off_t im_Synch( Img_t *ob ){
off_t siz ;
char *buf ;
buf = MagickGetImageBlob( ob ->wand, (size_t *) &siz ) ;
if( ob ->img ){
destroyBlob( ob ->img ) ;
}
ob ->img = copyBlob( buf, siz ) ;
MagickRelinquishMemory( buf ) ;
buf = (char *) MagickGetFilename( ob ->wand ) ;
ob ->img ->path = strdup( buf ) ;
MagickRelinquishMemory( buf ) ;
Do( ob, Geometry ) ;
return( siz ) ;
}
int im_Scale( Img_t *ob, long w, long h ){
int ret = 0 ;
if( ob ->wand ){
ret = MagickScaleImage( ob ->wand, w, h ) ;
im_Synch( ob ) ;
}
return( ret ) ;
}
int im_reScale( Img_t *ob, double scale ){
long w,h ;
if( scale != 1.0 ){
w = (long) (im_Width( ob ) * scale) ;
h = (long) (im_Height( ob ) * scale) ;
return( im_Scale( ob, w, h ) ) ;
}
return( 0 ) ;
}
Lst_t *im_GetProperties( Img_t *ob, char *pattern ){
int i ;
long n_Opts ;
char **txt ;
Lst_t *ret = (Lst_t *) NULL ;
txt = (char **) MagickGetImageProperties( ob ->wand, pattern, &n_Opts ) ;
if( n_Opts > 0 ){
ret = New( List, n_Opts ) ;
for( i = 0 ; i < n_Opts ; i++ ){
Do( ret, Add, txt );
}
}
MagickRelinquishMemory( txt );
return( ret ) ;
}
Lst_t *im_GetOptions( Img_t *ob, char *pattern ){
int i ;
long n_Opts ;
char **txt ;
Lst_t *ret = (Lst_t *) NULL ;
txt = (char **) MagickGetOptions( ob ->wand, pattern, &n_Opts ) ;
if( n_Opts > 0 ){
ret = New( List, n_Opts ) ;
for( i = 0 ; i < n_Opts ; i++ ){
Do( ret, Add, txt );
}
}
MagickRelinquishMemory( txt );
return( ret ) ;
}
OUTPUT: (the same in both cases)
::: Original Image is 3456 x 2304 (8 bits deep) 3009772 bytes.
::: WIDTH = 3456
::: Resized Image is 691 x 460 (16 bits deep) 169017 bytes.
::: Image description:
Image:
Format: JPG (Joint Photographic Experts Group JFIF format)
Class: DirectClass
Geometry: 691x460+0+0
Base geometry: 3456x2304
Resolution: 72x72
Print size: 9.59722x6.38889
Units: PixelsPerInch
Type: TrueColor
Endianess: Undefined
Colorspace: RGB
Depth: 16-bit
Channel depth:
Red: 16-bit
Green: 16-bit
Blue: 16-bit
Channel statistics:
Red:
Min: 875 (0.0133516)
Max: 65535 (1)
Mean: 37346.1 (0.569865)
Standard deviation: 12233.5 (0.186671)
Green:
Min: 1412 (0.0215457)
Max: 65060 (0.992752)
Mean: 35160.3 (0.536512)
Standard deviation: 12131.6 (0.185116)
Blue:
Min: 40 (0.000610361)
Max: 62601 (0.95523)
Mean: 26110.2 (0.398416)
Standard deviation: 9765.74 (0.149016)
Rendering intent: Undefined
Interlace: None
Background color: white
Border color: rgb(223,223,223)
Matte color: grey74
Transparent color: black
Page geometry: 691x460+0+0
Dispose: Undefined
Iterations: 0
Compression: JPEG
Quality: 98
Orientation: TopLeft
Properties:
Exif:ApertureValue: 370648/65536
Exif:ColorSpace: 1
Exif:ComponentsConfiguration: ...
Exif:Compression: 6
Exif:CustomRendered: 0
Exif:DateTime: 2006:07:31 04:01:56
Exif:DateTimeDigitized: 2006:07:31 04:01:56
Exif:DateTimeOriginal: 2006:07:31 04:01:56
Exif:ExifImageLength: 2304
Exif:ExifImageWidth: 3456
Exif:ExifOffset: 196
Exif:ExifVersion: 0221
Exif:ExposureBiasValue: 0/2
Exif:ExposureMode: 0
Exif:ExposureProgram: 2
Exif:ExposureTime: 1/500
Exif:Flash: 16 Exif:FlashPixVersion: 0100
Exif:FNumber: 71/10
Exif:FocalLength: 260/1
Exif:FocalPlaneResolutionUnit: 2
Exif:FocalPlaneXResolution: 3456000/874
Exif:FocalPlaneYResolution: 2304000/582
Exif:InteroperabilityIndex: R98
Exif:InteroperabilityOffset: 9230
Exif:InteroperabilityVersion: 0100
Exif:ISOSpeedRatings: 400
Exif:JPEGInterchangeFormat: 9716
Exif:JPEGInterchangeFormatLength: 7434
Exif:Make: Canon
Exif:MakerNote: .
Exif:MeteringMode: 5
Exif:Model: Canon EOS DIGITAL REBEL XT
Exif:Orientation: 1
Exif:ResolutionUnit: 2
Exif:SceneCaptureType: 0
Exif:ShutterSpeedValue: 587582/65536
Exif:WhiteBalance: 0
Exif:XResolution: 72/1
Exif:YCbCrPositioning: 2
Exif:YResolution: 72/1
Jpeg:colorspace: 2
Jpeg:sampling-factor: 2x1,1x1,1x1
Signature: cd99354963ab27f03d13aa5e0345176979a296126162038470f5859b3e29d2b4
Profiles:
Profile-exif: 17158 bytes
Tainted: True
Filesize: 165.055kb
Number pixels: 310.41kb
Pixels per second: 155.205kb
User time: 2.531u
Elapsed time: 0:03
Version: ImageMagick 6.3.9 02/28/08 Q16 http://www.imagemagick.org
::: Image Profiles:
exif
::: Image Properties:
exif:ApertureValue
exif:ColorSpace
exif:ComponentsConfiguration
exif:Compression
exif:CustomRendered
exif:DateTime
exif:DateTimeDigitized
exif:DateTimeOriginal
exif:ExifImageLength
exif:ExifImageWidth
exif:ExifOffset
exif:ExifVersion
exif:ExposureBiasValue
exif:ExposureMode
exif:ExposureProgram
exif:ExposureTime
exif:Flash
exif:FlashPixVersion
exif:FNumber
exif:FocalLength
exif:FocalPlaneResolutionUnit
exif:FocalPlaneXResolution
exif:FocalPlaneYResolution
exif:InteroperabilityIndex
exif:InteroperabilityOffset
exif:InteroperabilityVersion
exif:ISOSpeedRatings
exif:JPEGInterchangeFormat
exif:JPEGInterchangeFormatLength
exif:Make
exif:MakerNote
exif:MeteringMode
exif:Model
exif:Orientation
exif:ResolutionUnit
exif:SceneCaptureType
exif:ShutterSpeedValue
exif:WhiteBalance
exif:XResolution
exif:YCbCrPositioning
exif:YResolution
jpeg:colorspace
jpeg:sampling-factor
signature
::: orient:
1
Mel uname -a's as:
FreeBSD mel.controlq.com 6.2-RELEASE FreeBSD 6.2-RELEASE #1: Thu May 17 12:24:25 EDT 2007 rob@mel.controlq.com:/usr/src/sys/i386/compile/mel i386
I display the image on the same machine as I generate it, to take the X11 over the wire out of the equation
but timings are significant.
mel:
6.3.8 -
7.59 real 6.04 user 0.20 sys
7.47 real 6.08 user 0.17 sys
7.48 real 6.06 user 0.20 sys
mel:
6.3.9 - 53.08 real 48.54 user 0.37 sys
51.47 real 48.59 user 0.23 sys
51.67 real 48.66 user 0.22 sys
Q_Main is the routine I'm running, and library routines are pasted below for
reference. The Do( pic ...) macros simply invoke the im_XXXX( obj, args ... ),
So basically:
im_getFile: read file into a blob, then copy over to a wand in my
struct (i keep both a blob and a wand).
im_reScale: MagickScaleImage()
guiSetObjVar writes the Blob to a TK image (displays it)
im_GetProperties ->MagickGetImageProperties
im_GetOptions -> MagickGetOptions
Pretty straighforward ... sample code is below, and I used the Bourne shell time command
to provide the data above ...
int Q_Main( Tcl_Interp *interp ) {
Img_t *pic ;
long w ;
Lst_t *x ;
pic = New( Photo ) ;
Do( pic, GetFile, "/u0/Archive/20060730/A/img_0100.jpg" ) ;
printf( "::: Original Image is %ld x %ld (%ld bits deep) %ld bytes.\n",
Do( pic, Width), Do( pic,Height), Do( pic, Depth ), pic ->img ->size ) ;
w = Do( pic, Width ) ;
printf( "::: WIDTH = %ld\n", w ) ;
if( w > (long) 2048 ){
Do( pic, reScale, (double) .2 ) ;
}
guiSetObjVar( "imgX", 0, pic ->img ) ;
printf( "::: Resized Image is %ld x %ld (%ld bits deep) %ld bytes.\n",
Do( pic, Width), Do( pic,Height), Do( pic, Depth ), pic ->img ->size ) ;
printf( "::: Image description:\n\t%s\n", Do( pic, Describe ) ) ;
x = Do( pic, GetProfiles, "*" ) ;
if( x ){
printf( "::: Image Profiles:\n" ) ;
Do( x, Dump, 1 ) ;
Do( x, Destroy ) ;
}
x = Do( pic, GetProperties, 0, "*" ) ;
if( x ){
printf( "::: Image Properties:\n" ) ;
Do( x, Dump, 1 ) ;
Do( x, Destroy ) ;
}
x = Do( pic, GetOptions, 0, "*" ) ;
if( x ){
printf( "::: Image Options:\n" ) ;
Do( x, Dump, 1 ) ;
Do( x, Destroy ) ;
}
printf( "::: orient:\n\t%s\n", Do( pic, GetProperty, "exif:Orientation" ) ) ;
Exec_Tcl( code ) ;
Tk_MainLoop() ;
return( TCL_OK ) ;
}
Img_t *im_GetFile( Img_t *ob, char *path ){
if( ob ->img ){
destroyBlob( ob ->img ) ;
}
ob ->img = getFile( path ) ;
if( !ob ->wand ){
ob ->wand = NewMagickWand() ;
}
ClearMagickWand( ob ->wand ) ;
MagickReadImageBlob( ob ->wand, ob ->img ->buf, ob ->img ->actual ) ;
MagickSetFilename( ob ->wand, ob ->img ->path ) ;
return( ob ) ;
}
off_t im_Synch( Img_t *ob ){
off_t siz ;
char *buf ;
buf = MagickGetImageBlob( ob ->wand, (size_t *) &siz ) ;
if( ob ->img ){
destroyBlob( ob ->img ) ;
}
ob ->img = copyBlob( buf, siz ) ;
MagickRelinquishMemory( buf ) ;
buf = (char *) MagickGetFilename( ob ->wand ) ;
ob ->img ->path = strdup( buf ) ;
MagickRelinquishMemory( buf ) ;
Do( ob, Geometry ) ;
return( siz ) ;
}
int im_Scale( Img_t *ob, long w, long h ){
int ret = 0 ;
if( ob ->wand ){
ret = MagickScaleImage( ob ->wand, w, h ) ;
im_Synch( ob ) ;
}
return( ret ) ;
}
int im_reScale( Img_t *ob, double scale ){
long w,h ;
if( scale != 1.0 ){
w = (long) (im_Width( ob ) * scale) ;
h = (long) (im_Height( ob ) * scale) ;
return( im_Scale( ob, w, h ) ) ;
}
return( 0 ) ;
}
Lst_t *im_GetProperties( Img_t *ob, char *pattern ){
int i ;
long n_Opts ;
char **txt ;
Lst_t *ret = (Lst_t *) NULL ;
txt = (char **) MagickGetImageProperties( ob ->wand, pattern, &n_Opts ) ;
if( n_Opts > 0 ){
ret = New( List, n_Opts ) ;
for( i = 0 ; i < n_Opts ; i++ ){
Do( ret, Add, txt );
}
}
MagickRelinquishMemory( txt );
return( ret ) ;
}
Lst_t *im_GetOptions( Img_t *ob, char *pattern ){
int i ;
long n_Opts ;
char **txt ;
Lst_t *ret = (Lst_t *) NULL ;
txt = (char **) MagickGetOptions( ob ->wand, pattern, &n_Opts ) ;
if( n_Opts > 0 ){
ret = New( List, n_Opts ) ;
for( i = 0 ; i < n_Opts ; i++ ){
Do( ret, Add, txt );
}
}
MagickRelinquishMemory( txt );
return( ret ) ;
}
OUTPUT: (the same in both cases)
::: Original Image is 3456 x 2304 (8 bits deep) 3009772 bytes.
::: WIDTH = 3456
::: Resized Image is 691 x 460 (16 bits deep) 169017 bytes.
::: Image description:
Image:
Format: JPG (Joint Photographic Experts Group JFIF format)
Class: DirectClass
Geometry: 691x460+0+0
Base geometry: 3456x2304
Resolution: 72x72
Print size: 9.59722x6.38889
Units: PixelsPerInch
Type: TrueColor
Endianess: Undefined
Colorspace: RGB
Depth: 16-bit
Channel depth:
Red: 16-bit
Green: 16-bit
Blue: 16-bit
Channel statistics:
Red:
Min: 875 (0.0133516)
Max: 65535 (1)
Mean: 37346.1 (0.569865)
Standard deviation: 12233.5 (0.186671)
Green:
Min: 1412 (0.0215457)
Max: 65060 (0.992752)
Mean: 35160.3 (0.536512)
Standard deviation: 12131.6 (0.185116)
Blue:
Min: 40 (0.000610361)
Max: 62601 (0.95523)
Mean: 26110.2 (0.398416)
Standard deviation: 9765.74 (0.149016)
Rendering intent: Undefined
Interlace: None
Background color: white
Border color: rgb(223,223,223)
Matte color: grey74
Transparent color: black
Page geometry: 691x460+0+0
Dispose: Undefined
Iterations: 0
Compression: JPEG
Quality: 98
Orientation: TopLeft
Properties:
Exif:ApertureValue: 370648/65536
Exif:ColorSpace: 1
Exif:ComponentsConfiguration: ...
Exif:Compression: 6
Exif:CustomRendered: 0
Exif:DateTime: 2006:07:31 04:01:56
Exif:DateTimeDigitized: 2006:07:31 04:01:56
Exif:DateTimeOriginal: 2006:07:31 04:01:56
Exif:ExifImageLength: 2304
Exif:ExifImageWidth: 3456
Exif:ExifOffset: 196
Exif:ExifVersion: 0221
Exif:ExposureBiasValue: 0/2
Exif:ExposureMode: 0
Exif:ExposureProgram: 2
Exif:ExposureTime: 1/500
Exif:Flash: 16 Exif:FlashPixVersion: 0100
Exif:FNumber: 71/10
Exif:FocalLength: 260/1
Exif:FocalPlaneResolutionUnit: 2
Exif:FocalPlaneXResolution: 3456000/874
Exif:FocalPlaneYResolution: 2304000/582
Exif:InteroperabilityIndex: R98
Exif:InteroperabilityOffset: 9230
Exif:InteroperabilityVersion: 0100
Exif:ISOSpeedRatings: 400
Exif:JPEGInterchangeFormat: 9716
Exif:JPEGInterchangeFormatLength: 7434
Exif:Make: Canon
Exif:MakerNote: .
Exif:MeteringMode: 5
Exif:Model: Canon EOS DIGITAL REBEL XT
Exif:Orientation: 1
Exif:ResolutionUnit: 2
Exif:SceneCaptureType: 0
Exif:ShutterSpeedValue: 587582/65536
Exif:WhiteBalance: 0
Exif:XResolution: 72/1
Exif:YCbCrPositioning: 2
Exif:YResolution: 72/1
Jpeg:colorspace: 2
Jpeg:sampling-factor: 2x1,1x1,1x1
Signature: cd99354963ab27f03d13aa5e0345176979a296126162038470f5859b3e29d2b4
Profiles:
Profile-exif: 17158 bytes
Tainted: True
Filesize: 165.055kb
Number pixels: 310.41kb
Pixels per second: 155.205kb
User time: 2.531u
Elapsed time: 0:03
Version: ImageMagick 6.3.9 02/28/08 Q16 http://www.imagemagick.org
::: Image Profiles:
exif
::: Image Properties:
exif:ApertureValue
exif:ColorSpace
exif:ComponentsConfiguration
exif:Compression
exif:CustomRendered
exif:DateTime
exif:DateTimeDigitized
exif:DateTimeOriginal
exif:ExifImageLength
exif:ExifImageWidth
exif:ExifOffset
exif:ExifVersion
exif:ExposureBiasValue
exif:ExposureMode
exif:ExposureProgram
exif:ExposureTime
exif:Flash
exif:FlashPixVersion
exif:FNumber
exif:FocalLength
exif:FocalPlaneResolutionUnit
exif:FocalPlaneXResolution
exif:FocalPlaneYResolution
exif:InteroperabilityIndex
exif:InteroperabilityOffset
exif:InteroperabilityVersion
exif:ISOSpeedRatings
exif:JPEGInterchangeFormat
exif:JPEGInterchangeFormatLength
exif:Make
exif:MakerNote
exif:MeteringMode
exif:Model
exif:Orientation
exif:ResolutionUnit
exif:SceneCaptureType
exif:ShutterSpeedValue
exif:WhiteBalance
exif:XResolution
exif:YCbCrPositioning
exif:YResolution
jpeg:colorspace
jpeg:sampling-factor
signature
::: orient:
1
Re: 6.3.9 performance regession?
Unfortunately we still cannot help. We require demonstation code that we can download and compile and that includes only those ImageMagick methods that has been identified as the source of the performance degradation. Once we can reproduce the performance degradation we will account for it, suggest a workaround, or apply a patch to fix the problem.
-
paraplegic
Re: 6.3.9 performance regession?
Hmmm ... understood. I wrote a small test program which uses all the ImageMagick routines that I call in roughly the same order, and I cannot reproduce the delay. Oddly, the timing numbers I gave above *CAN* be reproduce at will on my code, but I'm not sure why. I will attempt to perform some gprof traces upon my code ... by the way, does the ./configure --enable-gprof flag work on IM? I don't seem to be getting any gprof traces past my own code at this point ... and there is nothing conclusive at this point.magick wrote:Unfortunately we still cannot help. We require demonstation code that we can download and compile and that includes only those ImageMagick methods that has been identified as the source of the performance degradation. Once we can reproduce the performance degradation we will account for it, suggest a workaround, or apply a patch to fix the problem.
Strange,
Thanks for your interest, though
Rob.
Re: 6.3.9 performance regession?
You can determine if the --enable-grof configure script command-line option is working by performing a build and looking for the -pg option on the gcc command-line.
In regards to performance degradation, our own tests show a 20% speed-up between ImageMagick 6.3.7 and 6.3.9. However, its possible that a particular operation may be aberant.
In regards to performance degradation, our own tests show a 20% speed-up between ImageMagick 6.3.7 and 6.3.9. However, its possible that a particular operation may be aberant.