[BUG] Consumer consuming files to often with inotify

[martinpichlo]

I'm using a printer-scanner solution (Canon Maxify MB5150) to scan documents via Samba (SMB1) into the consume directory of paperless-ng. It seems, that inotify triggers new files to often.

After "sending" a new document to paperless-ng via consume directory, I found the following within the protocol:

1. After "Adding" and "Consuming" the new document at the beginning, three "Adding" entries are following.
2. After "Saving record to database" I found a succesfully "Deleting file".
3. But at the end there a three "Cannot consume.... File not found" entries.

Here are my protocol:

[2021-03-25 09:33:41,055] [INFO] [paperless.management.consumer] Adding /usr/src/paperless/src/../consume/SCN_0001.pdf to the task queue.
[2021-03-25 09:33:41,226] [INFO] [paperless.consumer] Consuming SCN_0001.pdf
[2021-03-25 09:33:41,229] [DEBUG] [paperless.consumer] Detected mime type: application/pdf
[2021-03-25 09:33:41,706] [INFO] [paperless.management.consumer] Adding /usr/src/paperless/src/../consume/SCN_0001.pdf to the task queue.
[2021-03-25 09:33:51,040] [INFO] [paperless.management.consumer] Adding /usr/src/paperless/src/../consume/SCN_0001.pdf to the task queue.
[2021-03-25 09:33:51,580] [INFO] [paperless.management.consumer] Adding /usr/src/paperless/src/../consume/SCN_0001.pdf to the task queue.
[2021-03-25 09:35:41,345] [DEBUG] [paperless.consumer] Parser: RasterisedDocumentParser
[2021-03-25 09:35:41,356] [DEBUG] [paperless.consumer] Parsing SCN_0001.pdf...
[2021-03-25 09:35:41,497] [DEBUG] [paperless.parsing.tesseract] Extracted text from PDF file /usr/src/paperless/src/../consume/SCN_0001.pdf
[2021-03-25 09:35:41,678] [DEBUG] [paperless.parsing.tesseract] Calling OCRmyPDF with args: {'input_file': '/usr/src/paperless/src/../consume/SCN_0001.pdf', 'output_file': '/tmp/paperless/paperless-4qucdra4/archive.pdf', 'use_threads': True, 'jobs': 1, 'language': 'deu', 'output_type': 'pdfa', 'progress_bar': False, 'skip_text': True, 'clean': True, 'deskew': True, 'rotate_pages': True, 'rotate_pages_threshold': 12.0, 'sidecar': '/tmp/paperless/paperless-4qucdra4/sidecar.txt'}
[2021-03-25 09:36:10,173] [DEBUG] [paperless.parsing.tesseract] Using text from sidecar file
[2021-03-25 09:36:10,175] [DEBUG] [paperless.consumer] Generating thumbnail for SCN_0001.pdf...
[2021-03-25 09:36:10,187] [DEBUG] [paperless.parsing] Execute: convert -density 300 -scale 500x5000> -alpha remove -strip -auto-orient /tmp/paperless/paperless-4qucdra4/archive.pdf[0] /tmp/paperless/paperless-4qucdra4/convert.png
[2021-03-25 09:36:11,780] [DEBUG] [paperless.parsing.tesseract] Execute: optipng -silent -o5 /tmp/paperless/paperless-4qucdra4/convert.png -out /tmp/paperless/paperless-4qucdra4/thumb_optipng.png
[2021-03-25 09:36:18,647] [DEBUG] [paperless.classifier] Document classification model does not exist (yet), not performing automatic matching.
[2021-03-25 09:36:18,656] [DEBUG] [paperless.consumer] Saving record to database
...some tagging....
[2021-03-25 09:36:18,808] [DEBUG] [paperless.consumer] Deleting file /usr/src/paperless/src/../consume/SCN_0001.pdf
[2021-03-25 09:36:18,812] [DEBUG] [paperless.parsing.tesseract] Deleting directory /tmp/paperless/paperless-4qucdra4
[2021-03-25 09:36:18,813] [INFO] [paperless.consumer] Document 2021-03-18 dummy SCN_0001 consumption finished
[2021-03-25 09:36:19,136] [ERROR] [paperless.consumer] Cannot consume /usr/src/paperless/src/../consume/SCN_0001.pdf: File not found.
[2021-03-25 09:36:20,116] [ERROR] [paperless.consumer] Cannot consume /usr/src/paperless/src/../consume/SCN_0001.pdf: File not found.
[2021-03-25 09:36:20,622] [ERROR] [paperless.consumer] Cannot consume /usr/src/paperless/src/../consume/SCN_0001.pdf: File not found.

Some details of my paperless-ng installation:

• I'm using the docker version of paperless-ng
• I set up "PAPERLESS_FILENAME_FORMAT={correspondent}/{created_year}/{title}" in docker-compose.env

PS: In parallel I have the problem, that inotify was consuming newly created scans within the consume directory to early. This results in incomplete documents in paperless. The reason for that is, that the printer is creating new files right at the beginning and expand it bit by bit while scanning. I have described that in an separate discussion #463 which belongs to
#462. As temporary workarround I created a pre consuming script which simply waits two minutes. Importing: Is makes no difference to the error above, if I active or deactivate this workarround.

Any ideas?

[jonaswinkler]

Well, apparently your scanner / network setup writes the files and closes them multiple times while writing. This triggers inotify. Nothing you can do about that, inotify simply does not work for you. You need to use PAPERLESS_CONSUMER_POLLING.

[jonaswinkler]

Intofiy listens for the events close_write (someone finished writing to a file) and moved (someone wrote to a file that's ignored, such as doc.pdf.filepart, and then moved that file).

This is enough in most cases.

The Polling consumer does not use inotify at all, and has the logic outlined by you implemented:

paperless-ng/src/documents/management/commands/document_consumer.py

Line 73 in ccaee4c

def _consume_wait_unmodified(file):

[VanillaChief]

I observed the same behavior, but without using a scanner. If I move files into my consume folder (e.g. by drag and drop in Finder) it triggers multiple queue entries. The output is fine, since after the first is finished it says that the checksum for the next is not unique and stops. If I first put the files in the same directory as the consume folder and then into the consume folder itself, the consumption is normal. First I thought it was a problem with moving files from my Mac to the DiskStation, but this also happens if I move it in the Synology from my personal documents folder directly into the consume folder.

I use a docker installation on a Synology DS220+.

[VanillaChief]

Additional observation: It only happens when I use Finder. When I do the same thing in FileStation in the DSM UI, it works fine.

[skorvek]

Does this imply that Mac+SAMBA does something where inotify isn't the appropriate mechanism - they we should use poling in this case? I see the same thing- simple drag & drop using Finder into the shared directory creates multiple jobs for the end file as well as for the annoying shadow mac metadata file.

[jonaswinkler]

I think I've heard this problem before w.r.t. Mac OS. If you're getting multiple jobs per file, not counting the shadow files, that's an issue with how mac copies files onto samba shares. I suppose it's better to use polling.

I've also considered to make polling the default for a while now.