Imageprocessor: Wrong image saved in cache

[etharion]

Versions

ImageProcessor: 2.8.0
ImageProcessor.Web: 4.11.0
ImageProcessor.Web.Config: 2.6.0
ImageProcessor.Web.PostProcessor: 1.5.0
Umbraco: 7.11.1
.NET Framework version: 4.6.1

Description

We experience that the wrong images gets cached. For example in Umbraco you have the media archive with images uploaded on different nodes. When printing the HTML for the images, we first find the node and then the node contains information about which image file on the server to use. We use the img tag with a srcset, so we have multiple sizes (multiple cached images of the same image) for each image. It is here we experience one of the sizes will have another image from the media archive than the others, which is odd since the same node has been used to create the srcset. Haven't been able to find a stable way of reproducing this, but clear the cache and load images again (different images gets the wrong images from each cache clear). It is only happening to very few images, rough guess we experienced this on 5 out of 1000 images.

Examples of different sizes:
/media/6934/irish-turnout-black.jpg?width=1110&rnd=201808100858&heightratio=1&quality=80&bgcolor=ffffff

/media/6934/irish-turnout-black.jpg?width=750&rnd=201808100858&heightratio=1&quality=80&bgcolor=ffffff

A single of the sizes as shown here would show a different image apart from the others in the img tag and the querys would not be applied correctly either.
/media/6934/irish-turnout-black.jpg?width=350&rnd=201808100858&heightratio=1&quality=80&bgcolor=ffffff

The 'rnd'-query, we tried to get the last write date of the image file in hope that was enough to update the cache, but with no luck.

If needed I can send the project with a database. If anything else needed, I will try to answer. But this is mostly all we got about it.

System Configuration

Windows 10 | Windows Server 2016
MSSQL 14

[JimBobSquarePants]

This doesn't look like an ImageProcessor issue to me. Perhaps talk to someone at Umbraco.

Cached file paths are generated based on the full path and the querystring.

https://github.com/JimBobSquarePants/ImageProcessor/blob/61eb3195c37b840370a10126f57feb797741a306/src/ImageProcessor.Web/Caching/ImageCacheBase.cs#L155

[ronaldbarendse]

Looks like the GetCachedImageFileName method only uses the supplied full path to generate the cache name:
https://github.com/JimBobSquarePants/ImageProcessor/blob/61eb3195c37b840370a10126f57feb797741a306/src/ImageProcessor.Web/Caching/CachedImageHelper.cs#L54-L68

Although I haven't seen this behaviour myself, this might be introduced in the latest versions... This will definitely require more testing to be sure though!

[JimBobSquarePants]

path is not just the pathbase and inlcudes the querystring. The querystring parameter is only used separately to help get the correct extension.

[etharion]

I'm testing this abit more. I have a simple html page, where I print out original image and the processed, with the query as live environment has it, next to eachother. I have a hard time finding any problems for this on my locale with this domain: test-milj.dk.localhost. When I uploaded my little test page to the live environment, I immediately found a mismatch.
Do you use the machine/server id for hashing, assuming you are creating a hash per cached item?
Can we be hitting a scenario where pictures have the same hash and therefore I get an image which URL is different from what is expected?
Does .local or .localhost have any affect on how imageprocessor does things?

I will today, try my test page with older version of packages: ImageProcessor, ImageProcessor.Web, ImageProcessor.Web.Config and ImageProcessor.Web.PostProcessor

[etharion]

We have now gone back to version: 2.5.6 of ImageProcessor and the problem still occurs. So I assume its not a version issue. We have only noticed the problem happen to .png, not .jpg.
Could there be something about this?
And is there any other information you would like provided?

[JimBobSquarePants]

All image formats run through exactly the same pipeline. All cache hash generation is based on the request URL only and has a very low collision rate. (Millions to one)

I can only say that you should build the library from source, adding whatever logging you require and debug the issue. There is nothing that we can do here to help you as we cannot replicate the issue and no one else has reported it.

[ronaldbarendse]

My best guess would be that this is an issue with the PostProcessor, as that temporarly generates files using Path.GetTempFileName() and then changes the extension, before doing the processing.

This method can only generate up to 65535 unique files, so if a lot of sites/programs use this framework method, it might return the same temporary file name within the time PostProcessor is still processing another image (as the extension is changed, the same file name can be returned again).

So this is probably happening within PostProcessor:

• Request a unique temporary file name using Path.GetTempFileName()
• Change the extension, thereby allowing Path.GetTempFileName() to return the same temporary file name again
• Write the source image to the temporary file name with correct extension and start processing
• While it's processing, a new request comes in and does all the above steps using the same unique file name
• Now the image of the first request is overwritten and gets cached for all remaining requests
• The second request completes normally (if it can still find the temporary file) or if the previous request sucessfully deleted the temporary file, assumes it can't optimize the image and uses the original/unoptimzed image

[ronaldbarendse]

A quick fix would be to keep the temporary file name around while processing the image, so we should remove this line:

https://github.com/JimBobSquarePants/ImageProcessor/blob/280c8a8dcd91703f81527774b74c997d127a3549/src/ImageProcessor.Web.Plugins.PostProcessor/PostProcessor.cs#L59

And clean up the tempSourceFile file after processing is done:
https://github.com/JimBobSquarePants/ImageProcessor/blob/280c8a8dcd91703f81527774b74c997d127a3549/src/ImageProcessor.Web.Plugins.PostProcessor/PostProcessor.cs#L128-L150

[ronaldbarendse]

I've also seen the following exception from multiple sites, so it might be worthwhile to rewrite the temporary processing location:

System.UnauthorizedAccessException: Access to the path 'C:\\Windows\\TEMP\\tmpA383-out.png' is denied.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share)
   at ImageProcessor.Web.Plugins.PostProcessor.PostProcessor.PostProcessImage(HttpContext context, MemoryStream stream, String extension)
   at ImageProcessor.Web.Plugins.PostProcessor.PostProcessorApplicationEvents.PostProcess(Object sender, PostProcessingEventArgs e)
   at ImageProcessor.Web.HttpModules.ImageProcessingModule.d__35.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.AsyncEventExecutionStep.InvokeEndHandler(IAsyncResult ar)
   at System.Web.HttpApplication.AsyncEventExecutionStep.OnAsyncEventCompletion(IAsyncResult ar)

This is from an older ImageProcessor.Web.PostProcessor version: 1.3.1.25, but the issue should be the same on the latest version.

Looking at the file name and stack trace, it might also be because the PNG post processing timed out and it couldn't copy over the destination file (as it was still in use by PNGQuant/TruePNG/Pingo):
https://github.com/JimBobSquarePants/ImageProcessor/blob/280c8a8dcd91703f81527774b74c997d127a3549/src/ImageProcessor.Web.Plugins.PostProcessor/PostProcessor.cs#L102-L106

[etharion]

This starts to look like something. It all seems to point towards the things we experience. Thanks for helping digging into this. Good work @ronaldbarendse @JimBobSquarePants. Is the quick fix, Ronald mentions, something we are able to get a temp version of? Or do we need another hotfix according to Ronalds last comment?

Again, thanks for helping. The issue is starting to be business critical for the client. Your help is appreciated!

[ronaldbarendse]

I'm actually very confident it's because Path.GetTempFileName() returns the same temporary file name after seeing this exception:

System.IO.IOException: Cannot create a file when that file already exists.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.__Error.WinIOError()
   at System.IO.File.InternalMove(String sourceFileName, String destFileName, Boolean checkHost)
   at ImageProcessor.Web.Plugins.PostProcessor.PostProcessor.PostProcessImage(HttpContext context, MemoryStream stream, String extension)
   at ImageProcessor.Web.Plugins.PostProcessor.PostProcessorApplicationEvents.PostProcess(Object sender, PostProcessingEventArgs e)
   at ImageProcessor.Web.HttpModules.ImageProcessingModule.d__35.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.TaskAsyncHelper.EndTask(IAsyncResult ar)
   at System.Web.HttpApplication.AsyncEventExecutionStep.InvokeEndHandler(IAsyncResult ar)
   at System.Web.HttpApplication.AsyncEventExecutionStep.OnAsyncEventCompletion(IAsyncResult ar)

The only move operation in PostProcessor is to give the temporary file it's new extension, so this can only happen when another request just recieved the same name, but already moved the file. If the current request has the same extension (so that reduces the chances a little bit), it tries to move to an existing file and this exception is thrown...

[ronaldbarendse]

@etharion The easiest fix is to uninstall ImageProcessor.Web.Plugins.PostProcessor and remove the cached files...

[JimBobSquarePants]

Fixed and deployed to Nuget