"The storage backend did not save the file" warnings and "IOError: [Errno 2] No such file or directory"

[idealatom]

Hello. I came across a problem with imagekit. I see a lot of warnings in Sentry from _generate method of ImageCacheFile - "The storage backend %s did not save the file with the requested name ("%s") and instead used "%s"". Also I have even more errors "IOError: [Errno 2] No such file or directory:"

IOError: [Errno 2] No such file or directory: u'/home/user/plitka/3dplitka/plitka/media/CACHE/images/images/tiles/images/europa-ceramica/dube/dec-angeles-dekor-01-20x50.a469216b4a05.jpeg'

Stacktrace (most recent call last):

  File "django/core/handlers/base.py", line 109, in get_response
    response = callback(request, *callback_args, **callback_kwargs)
  File "newrelic/hooks/framework_django.py", line 485, in wrapper
    return wrapped(*args, **kwargs)
  File "django/views/decorators/csrf.py", line 77, in wrapped_view
    return view_func(*args, **kwargs)
  File "plitka/catalog/views.py", line 868, in ajax_search
    style = 'style="margin: %dpx %dpx"' % ((82 - image.height) / 2, (82 - image.width) / 2)
  File "django/core/files/images.py", line 19, in _get_height
    return self._get_image_dimensions()[1]
  File "django/core/files/images.py", line 25, in _get_image_dimensions
    self.open()
  File "imagekit/files.py", line 58, in open
    self._require_file()
  File "imagekit/cachefiles/__init__.py", line 62, in _require_file
    self._file = self.storage.open(self.name, 'rb')
  File "django/core/files/storage.py", line 33, in open
    return self._open(name, mode)
  File "django/core/files/storage.py", line 155, in _open
    return File(open(self.path(name), mode))

This errors raises randomly, on different pages in small percent of requests . And if I reload same page right after error everything will be ok. There is no errors in my local devserver. Looks like some race condition situation. Here is different traceback:

IOError: [Errno 2] No such file or directory: u'/home/user/plitka/3dplitka/plitka/media/CACHE/images/santehnika/gemelli/glass-2/22684/gemelli-glass-2-glass-console-90-podvesnaya-colorglass.7017f7db9e2d.JPG'

Stacktrace (most recent call last):

  File "django/core/handlers/base.py", line 134, in get_response
    response = response.render()
  File "django/template/response.py", line 104, in render
    self._set_content(self.rendered_content)
  File "django/template/response.py", line 81, in rendered_content
    content = template.render(context)
  File "django/template/base.py", line 140, in render
    return self._render(context)
  File "newrelic/api/function_trace.py", line 79, in dynamic_wrapper
    return wrapped(*args, **kwargs)
  File "django/template/base.py", line 134, in _render
    return self.nodelist.render(context)
  File "django/template/base.py", line 823, in render
    bit = self.render_node(node, context)
  File "django/template/base.py", line 837, in render_node
    return node.render(context)
  File "django/template/loader_tags.py", line 123, in render
    return compiled_parent._render(context)
  File "newrelic/api/function_trace.py", line 79, in dynamic_wrapper
    return wrapped(*args, **kwargs)
  File "django/template/base.py", line 134, in _render
    return self.nodelist.render(context)
  File "django/template/base.py", line 823, in render
    bit = self.render_node(node, context)
  File "django/template/base.py", line 837, in render_node
    return node.render(context)
  File "django/template/loader_tags.py", line 123, in render
    return compiled_parent._render(context)
  File "newrelic/api/function_trace.py", line 79, in dynamic_wrapper
    return wrapped(*args, **kwargs)
  File "django/template/base.py", line 134, in _render
    return self.nodelist.render(context)
  File "django/template/base.py", line 823, in render
    bit = self.render_node(node, context)
  File "django/template/base.py", line 837, in render_node
    return node.render(context)
  File "newrelic/hooks/framework_django.py", line 685, in wrapper
    return wrapped(*args, **kwargs)
  File "django/template/loader_tags.py", line 62, in render
    result = block.nodelist.render(context)
  File "django/template/base.py", line 823, in render
    bit = self.render_node(node, context)
  File "django/template/base.py", line 837, in render_node
    return node.render(context)
  File "django/template/base.py", line 874, in render
    output = self.filter_expression.resolve(context)
  File "django/template/base.py", line 571, in resolve
    obj = self.var.resolve(context)
  File "django/template/base.py", line 721, in resolve
    value = self._resolve_lookup(context)
  File "django/template/base.py", line 754, in _resolve_lookup
    current = getattr(current, bit)
  File "django/core/files/images.py", line 15, in _get_width
    return self._get_image_dimensions()[0]
  File "django/core/files/images.py", line 25, in _get_image_dimensions
    self.open()
  File "imagekit/files.py", line 58, in open
    self._require_file()
  File "imagekit/cachefiles/__init__.py", line 62, in _require_file
    self._file = self.storage.open(self.name, 'rb')
  File "django/core/files/storage.py", line 33, in open
    return self._open(name, mode)
  File "django/core/files/storage.py", line 155, in _open
    return File(open(self.path(name), mode))

I'm using Imagekit 3.2.4 with Django 1.4.14. This is my imagekit settings: IMAGEKIT_SPEC_CACHEFILE_NAMER = 'imagekit.cachefiles.namers.source_name_dot_hash'

This is my imagegenerators:

from imagekit import ImageSpec, register
from imagekit.processors import ResizeToFit, ResizeToFill

class ProductBigThumbnail(ImageSpec):
    processors = [ResizeToFit(290, 290, mat_color='white')]
    format = 'JPEG'
    options = {
        'quality': 95,
        'optimize': True,
        'progressive': True,
    }

class ProductThumbnail(ImageSpec):
    processors = [ResizeToFit(65, 65, mat_color='white')]
    format = 'JPEG'
    options = {
        'quality': 95,
        'optimize': True,
        'progressive': True,
    }

class ProductCardThumbnail(ImageSpec):
    processors = [ResizeToFit(180, 180, mat_color='white')]
    format = 'JPEG'
    options = {
        'quality': 95,
        'optimize': True,
        'progressive': True,
    }

class ProductCartThumbnail(ImageSpec):
    processors = [ResizeToFit(100, 100, mat_color='white')]
    format = 'JPEG'
    options = {
        'quality': 95,
        'optimize': True,
        'progressive': True,
    }

register.generator('plumbing:product_big_thumb', ProductBigThumbnail)
register.generator('plumbing:product_thumb', ProductThumbnail)
register.generator('plumbing:product_card_thumb', ProductCardThumbnail)
register.generator('plumbing:product_cart_thumb', ProductCartThumbnail)

Here's how I use its in templates:

{% generateimage 'plumbing:product_thumb' source=component.to_product.get_image as thumb %}
<img src="{{ thumb.url }}" width="{{ thumb.width }}" height="{{ thumb.height}}">

Also I have this function for generating thumbnails in views:

from imagekit.cachefiles import ImageCacheFile
from imagekit.registry import generator_registry
from imagekit.templatetags.imagekit import DEFAULT_THUMBNAIL_GENERATOR

def make_thumbnail(source, width, height, generator_id=None):
    if generator_id is None:
        generator_id = DEFAULT_THUMBNAIL_GENERATOR
    kwargs = {
        'source': source,
        'width': width,
        'height': height,
    }
    generator = generator_registry.get(generator_id, **kwargs)
    return ImageCacheFile(generator)

I use this function like here, where get_image function returns value of ImageField:

image = make_thumbnail(it.get_image(), 82, 82)
style = 'style="margin: %dpx %dpx"' % ((82 - image.height) / 2, (82 - image.width) / 2)

Could you tell me why warnings are happens? What is the possible cause of this warnings and errors?

[matthewwithanm]

Does the warning actually have those %ss in it? You should see a message with those replaced with the actual storage and filenames.

As for that warning, it's telling you that the storage backend decided to use a different file name. This will happen if the name is not available. Generally, this shouldn't happen, but it can be caused by multiple simultaneous attempts to generate the same image.

The IOError seems like maybe you're missing source files.

If you could create a reduced test case, that would make it a lot easier to help out.

[idealatom]

Does the warning actually have those %ss in it?

Of course no. I get various messages with different filenames. And I don't understand why it's happens. Could you describe what can cause the possible situation with multiple simultaneous attempts to generate the same image?

For example I get warning _"The storage backend did not save the file with the requested name ("/path-to-thumbnails/A.jpg") and instead used "/path-to-thumbnails/Adfge.jpg". When I look in directory "/path-to-thumbnails/" I see both equal images A.jpg and _Adfge.jpg.

The IOError seems like maybe you're missing source files.

No, the missing path in this error is a thumbnail path, not a source file. For example I get error "No such file or directory: /path-to-thumbnails/B.jpg'" But right after that, when I checking existence of B.jpg, it's already exists and error with this filename doesn't repeat anymore when I refresh page. It looks like sometimes a thumbnail doesn't have time to generate during first request and it generating after. That is why I get IOError and that is why missing file is existed when I check it.

If you could create a reduced test case, that would make it a lot easier to help out.

I would be glad to do it, but this warning and mistakes not always occur. I do not know how to cause them. They happens randomly 2-4 times in a day only on production server.

[nex2hex]

What is your IMAGEKIT_DEFAULT_CACHEFILE_STRATEGY in settings? By default it's 'imagekit.cachefiles.strategies.JustInTime' - images generated when u access url/width/height attr on it.

ImageField in Django forms first save record to db and then save file to destination folder, so u have a short period of time when record to image in db, but file does not exist on disk.

Simple solution to your case: 1) Ignore this errors (bad solution, u have 500 error) 2) Set IMAGEKIT_DEFAULT_CACHEFILE_STRATEGY = 'imagekit.cachefiles.strategies.Optimistic' in settings 3) or modify your function

def make_thumbnail(source, width, height, generator_id=None):
    if not os.path.exist(source):
        return None
   ...

and use tags someting like

{% if component.to_product.get_image|file_exist %}
{% generateimage 'plumbing:product_thumb' source=component.to_product.get_image as thumb %}
<img src="{{ thumb.url }}" width="{{ thumb.width }}" height="{{ thumb.height}}">
{% endif %}

and add file_exist function to templates https://docs.djangoproject.com/en/1.7/howto/custom-template-tags/#writing-custom-template-filters

def file_exist(value): # Only one argument.
    return os.path.exist(value)

[idealatom]

@nex2hex, thanks for your reply.

What is your IMAGEKIT_DEFAULT_CACHEFILE_STRATEGY in settings?

I don't set imagekit cachefile strategy in my settings.

I try your 2nd and 3rd solutions and report the results.

[matthewwithanm]

Could you describe what can cause the possible situation with multiple simultaneous attempts to generate the same image?

Doing anything that generates the image ({% generateimage %}, file.generate(), file.url, etc) while it's already being generated. There's no lock so it will simply attempt to save the file twice. After the first file is written, the storage backend will use a different filename for the second.

It looks like sometimes a thumbnail doesn't have time to generate during first request and it generating after. That is why I get IOError and that is why missing file is existed when I check it.

The default strategy generates the file synchronously as part of the request/response cycle so this isn't possible AFAIK.

Are you getting the warnings on the same files as the errors? Also, are you doing anything that would cause additional asynchronicity?

[idealatom]

Are you getting the warnings on the same files as the errors?

No, as I can see, files from warning and errors are different.

Also, are you doing anything that would cause additional asynchronicity?

No. I don't have any complicated environment. Every settings for imagekit are default, except CACHEFILE_NAMER, I use source_name_dot_hash.

I made additional research and found some new details. All thumbnail files from warning and errors have same size 82x82. I found in my code 2 places where I create thumbnails with a size of 82 pixels. In all of this places I use function make_thumbnail, so likely the problem in this function:

# plumbing/images.py

from imagekit.cachefiles import ImageCacheFile
from imagekit.registry import generator_registry
from imagekit.templatetags.imagekit import DEFAULT_THUMBNAIL_GENERATOR

def make_thumbnail(source, width, height, generator_id=None):
    if generator_id is None:
        generator_id = DEFAULT_THUMBNAIL_GENERATOR
    kwargs = {
        'source': source,
        'width': width,
        'height': height,
    }
    generator = generator_registry.get(generator_id, **kwargs)
    return ImageCacheFile(generator)

First piece of code: I create thumbnails in 2 inline admin classes:

# admin.py

from plumbing.images import make_thumbnail

class OrderItemInline(admin.TabularInline):

    def get_product_image(obj):
        p = obj.product
        if p:
            thumb = make_thumbnail(p.image_original, 82, 82)
            return '<a href="%s"><img src="%s"/></a>' % (get_admin_change_url(p), thumb.url)
    get_product_image.allow_tags = True
    get_product_image.short_description = u'Изображение'

    model = OrderItem
    fields = (
        get_product_image,
        'product',
        'price',
        'render_count',
        'full_price',
        'items',
        'get_portion',
        'count_available',
        'is_available'
    )
    readonly_fields = (
        get_product_image,
        'full_price',
        'render_count',
        'get_portion'
    )

class PlumbingOrderItemInline(admin.TabularInline):

    def product_image(obj):
        thumb = make_thumbnail(obj.product.get_image(), 82, 82)
        return '<a href="%s"><img src="%s"/></a>' % (get_admin_change_url(obj.product), thumb.url)
    product_image.allow_tags = True
    product_image.short_description = u'Изображение'

    model = PlumbingOrderItem
    fields = (
        product_image,
        'product',
        'price',
        'quantity',
    )
    readonly_fields = (product_image, )

Second piece of code: I create thumbnails in my view and set some css styles for them. Maybe the problem here is that I getting height and width in one line of code?

image = make_thumbnail(it.get_image(), 82, 82)
style = 'style="margin: %dpx %dpx"' % ((82 - image.height) / 2, (82 - image.width) / 2)
data.append({
    'type': "product",
    'url': it.get_absolute_url(),
    'image': image.url,
    'name': it.full_name,
    'producer_name': it.collection.producer.name,
    'collection_name': it.collection.name,
    'product_type': it.category.name,
    'style': style,
})

[nex2hex]

Force call of os.path.exist(source) will help you in this case

[idealatom]

@nex2hex, I add call of os.path.exist() in make_thumbnail function. Lets see if it works.

[alternativshik]

same bug for me...

[idealatom]

btw i'm still stuck with this issue)

[alternativshik]

@idealatom looks like with JIT strategy it works. IMAGEKIT_DEFAULT_CACHEFILE_STRATEGY = 'imagekit.cachefiles.strategies.JustInTime'

[idealatom]

@alternativshik but I already have this strategy enabled, since it is default strategy and I don't set it directly in settings

[alternativshik]

@idealatom yep... You'r right. Error still present...

[nex2hex]

IMAGEKIT_DEFAULT_CACHEFILE_STRATEGY = 'imagekit.cachefiles.strategies.Optimistic'

[alternativshik]

@nex2hex No. Same errors, but more often.

[alternativshik]

@nex2hex btw, latest imagekit && latest django 1.8.4, and ImageSpecField with ResizeToFit processor. It can't find CACHE files, but after reload page thumbs are present

[nex2hex]

show me your model and stacktrace please

[alternativshik]

@nex2hex https://dpaste.de/xisN and error IOError: [Errno 2] No such file or directory: u'MY_PATH_HERE/project/media/CACHE/images/posts/2013/12/30/f4bb8e11add347d8af517767140433d8/56afdff16f5716e0af37a19de9bfab25.jpg'

MY_PATH_HERE - it's just path to my project folder

[alternativshik]

@idealatom LOL. Я 3дплитку когда-то в году 12 переделывал импортилки товаров из экселя.

[idealatom]

@alternativshik =)) то-то я смотрю, ник знакомый - в истории коммитов мелькал)

[nex2hex]

Раз уж перешли на русский, отвечу подробнее

Ошибка IOError возникает примерно в таком случае

Создание нового объекта в товаре	Поведение пользователя на сайте
1 Вызов метода save() у объекта:	...
1.1 выполнение запроса sql insert	...
1.2 ...	пользователь загружает страницу и новый объект попадает в вывод
1.3 ...	при рендеринге страницы идет обращение к картинке, которая еще не сохранена на диск
1.4 ...	возникновение IOError
1.5 выполнение процессоров у ProcessedImageField	...
1.6 сохранение картинки на диск	...

Т.е. между выполнением запроса и появлением картинки на диске проходит значительное количество времени.

Решение этой проблемы я описал тут https://github.com/matthewwithanm/django-imagekit/issues/315#issuecomment-85433129

Если ставите стратегию IMAGEKIT_DEFAULT_CACHEFILE_STRATEGY = 'imagekit.cachefiles.strategies.Optimistic' - то создание всех превьюшек будет происходить при сохранении объекта. Если не исопльзовать в выводе полечение ширины и высоты превьюшек (а только вызов thumbnail.url ) , то при стратегии Optimistic ошибок не будет, она в этом случае не дергает метод _generate() (получение width и height дергают каждый раз и не кэшируют размеры - старайтесь не пользоваться ими).

При переключении на Optimistic надо пройти по всем ранее созданным превьюшкам и сгенерировать у них картинки (JustInTime генерирует при обращении к свойству, а не при сохранении):

for image in images:
   image.thumbnail.generate()
   image.medium.generate()

из-за того, что этого не сделал - и была куча ошибок

[alternativshik]

@nex2hex Так, ясно/понятно. Самое странное, что этот косяк вылез конкретно у меня после обновления с какой-то старой версии. До этого данная проблема не наблюдалась. Проблема совсем некритичная в моем случае, скорее немного неприятная) Как быть со старыми изображениями, для которых нет превьюшек, ведь для них они не будут создаваться при стратегии Optimistic? (Вариант перегенерации руками лучше исключить вообще.) Раньше как-то иначе работала генерация?

[nex2hex]

при оптимистик - только руками, да. И при добавлении нового поля в модель - не забывать перегенерировать тоже.

Если вариант неприемлем, то переключиться на JustInTime и

1) написать враппер для получения урла, который будет ловить эксепшены IOError и не использовать width height (они сильно снижают производительность - открывать картинку и получать ее размеры каждый раз дорого).

2) или переписать метод save у модели, чтобы сначала сохранял картинку на диск, а потом вносил изменения в базу

[alternativshik]

@nex2hex Спасибо за разъяснение. Можно закрывать.