WriteBlob Failed

[alex@shopnation.com]

We are having ImageMagick randomly fail on our production and jenkins server (Amazon Linux AMI release 2014.03).
At least one image unit test fails (out of 36) about 75% of the time on jenkins. We cannot reproduce this on our local machines (OS X 10.9.3).

In the unit test we are reading the image file resource to a BufferedImage and pass it to org.im4java.core.ConvertCmd
We get the output as a BufferedImage using org.im4java.core.Stream2BufferedImage.Stream2BufferedImage
Any ideas?
Thanks

command (from debugging im4java code):

Code: Select all

convert /var/folders/b0/xt1_s48d6rx2gll_hphsyr800000gn/T/im4java-8504080242364813800.png -crop 85x106+5-2 -repage 85x106+5-2 png32:-

stacktrace:

Code: Select all

org.im4java.core.CommandException: org.im4java.core.CommandException: convert: WriteBlob Failed `-' @ error/png.c/MagickPNGErrorHandler/1806.
	at org.im4java.core.ImageCommand.run(ImageCommand.java:215)
	at com.shopnation.util.core.graphics.ImageUtil.resizePreserveAspectRatio(ImageUtil.java:166)
	at com.shopnation.util.core.graphics.ImageUtilTest.testResize_AutoCrop_AnimatedGif(ImageUtilTest.java:574)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
	at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
	at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
Caused by: org.im4java.core.CommandException: convert: WriteBlob Failed `-' @ error/png.c/MagickPNGErrorHandler/1806.
	at org.im4java.core.ImageCommand.finished(ImageCommand.java:247)
	at org.im4java.process.ProcessStarter.run(ProcessStarter.java:314)
	at org.im4java.core.ImageCommand.run(ImageCommand.java:211)
	... 31 more

im4java version:

Code: Select all

<dependency>
	<groupId>im4java</groupId>
	<artifactId>im4java</artifactId>
	<version>1.1.0</version>
	<optional>true</optional>
</dependency>

convert version:

Code: Select all

[admin@jenkins ~]$ convert --version
Version: ImageMagick 6.8.9-1 Q16 x86_64 2014-05-28 http://www.imagemagick.org
Copyright: Copyright (C) 1999-2014 ImageMagick Studio LLC
Features: DPC OpenMP
Delegates: bzlib freetype jng jpeg lzma png tiff xml zlib

[magick]

WriteBlob() writes bytes to memory, memory-mapped disk, or disk. It is likely the process ran out of resources before the conversion completed. How much memory does the machine have? By default, if pixels are instead written to disk, how much temporary space is available? For disk, IM typically writes to /tmp. Do you have a small /tmp partition? If so you can point ImageMagick to another disk location for its temporary files. If memory is the issue, you can reduce the memory requirements and instead force the pixels to disk with the -limit memory 2GB option, for example.

[alex@shopnation.com]

I'm not 100% sure what IM is writing to in this case, but I think its a pipe that is read by the java process.
The machine is a amazon c3.large (2 cpus 3.75 GB memory). /tmp is at 2% usage of 14 GB.
I moved the unit test that was failing to another part of the file, which caused a different test (similar IM operation) to fail.
Is there some kind of logging I can enable to get a better idea of what is going wrong?
Thanks.
Update: I added a loop to that test to run 100 times and got 3 failures (same IM operation repeated 100 times).
Is it possible that the temporary file that im4java is creating is corrupted? Looks like im4java deletes the files after IM fails.

Code: Select all

[admin@jenkins ~]$ java -version
java version "1.7.0_55"
OpenJDK Runtime Environment (amzn-2.4.7.1.40.amzn1-x86_64 u55-b13)
OpenJDK 64-Bit Server VM (build 24.51-b03, mixed mode)

[alex@shopnation.com]

Still having this problem. Decided to work around it by having IM write to a temp file and then read it in java.

Here is one other thing I found:
I was able to "fix" this issue by using some nasty java reflection hacks to put a sleep right after the convert process was started, but right before the process output stream was read.
Values over 100ms seemed to fix this problem. 10ms sleep still resulted in the error. So this might be related so some strange process/pipe timing issue on amazon linux.