Problem/Motivation

If you have a temporary file and for some reason the file on the disk for it no longer exists, it logs an error every time file_cron() runs:

Could not delete temporary file x during garbage collection

Proposed resolution

The file is gone. Maybe log an error or warning once, then drop the record.

Remaining tasks

Address #12 and #14

User interface changes

API changes

Data model changes

Members fund testing for the Drupal project. Drupal Association Learn more

Comments

Berdir created an issue. See original summary.

slashrsm’s picture

Status: Active » Needs review
FileSize
1.16 KB

Something along those lines?

dawehner’s picture

That's non trivial given that many systems drop log messages quite quickly, so potentially you'll never see the message.

Berdir’s picture

Yes, that's true for all log messages yes, also like content being deleted. But it's better than spaming the log and causing even more useful messages to get lost :)

Version: 8.3.x-dev » 8.4.x-dev

Drupal 8.3.0-alpha1 will be released the week of January 30, 2017, which means new developments and disruptive changes should now be targeted against the 8.4.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

Berdir’s picture

Re-rolled and included the test from #2760347: file_cron does not remove orphaned entries. Will close that as duplicate. Please also credit those from that issue. Will also close #2850497: Unclear log message when CRON garbage collection is unable to clean up temporary files as duplicate.

Berdir’s picture

Berdir’s picture

For the record, we're seeing this from time to time on our systems, haven't been able to track down what exactly is causing it yet, but as I said, the file is gone and we wanted to delete it anyway.

The last submitted patch, 6: 2802803_6-test-only.patch, failed testing.

The last submitted patch, 6: 2802803_6-test-only.patch, failed testing.

Munavijayalakshmi’s picture

+++ b/core/modules/file/file.module
@@ -659,12 +659,10 @@ function file_cron() {
+          \Drupal::logger('file system')->warning('Temporary file "%path" that was deleted during garbage collection did not exist on the filesystem.', array('%path' => $file->getFileUri()));

+++ b/core/modules/file/tests/src/Kernel/DeleteTest.php
@@ -69,4 +69,29 @@ public function testInUse() {
+      ->fields(array(
+        'changed' => \Drupal::time()->getRequestTime() - ($this->config('system.file')->get('temporary_maximum_age') + 1),
+      ))

use short array syntax (new coding standard).

Fixed the short array syntax error.

LittleCoding’s picture

This error can also be triggered via the read permissions of the file being misconfigured. So it does not look like a good practice to force a delete in this case.

gapple’s picture

Closed #2725457: Managed file garbage collector should delete file entity even if physical file does not exst. as a duplicate. The major difference in the patch in that issue is that it also performs an is_writable() check if the file still exists.

gapple’s picture

In the comments for #1401558: Remove the usage handling logic from file_delete() where the file_exists() check was added, there was also a concern about deleting the file entity if the stream wrapper was only disabled.

Dane Powell’s picture

Issue summary: View changes
Status: Needs review » Reviewed & tested by the community

I posted a very similar patch in #2885525: Missing temporary files cause errors on cron (closed as dupe). I also detailed a few of the very many benign causes of this error.

The reason I didn't find this issue is because I was searching for the actual error message, which isn't posted anywhere here. I added it to the issue description.

This patch looks good to me.

catch’s picture

Status: Reviewed & tested by the community » Fixed

#12 and #14 both need answering still I think? What are the implications for trying to delete the file if it exists but can't be read for some reason, couldn't that cause even more errors?

Dane Powell’s picture

Status: Fixed » Needs work

I'm assuming this wasn't meant to be marked "fixed"...

Version: 8.4.x-dev » 8.5.x-dev

Drupal 8.4.0-alpha1 will be released the week of July 31, 2017, which means new developments and disruptive changes should now be targeted against the 8.5.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

lslinnet’s picture

I am not sure if this fits inside of this issue, but there is also the side effect of this "file_exists" check that if 100+ file_managed records turn up with missing files then we have a useless cron job that keeps checking the same 100 records over and over again.

This have happened on my current project which have caused the file_managed table to grow to a few millions records, where a large amount of these are temporary files that should have been deleted along time ago.

Perhaps implementing a sort order in the lookup query, so it takes the most recent first would be a simple way to avoid an endless deadlock?

marcoscano’s picture

I'm experiencing this too. An easy way to reproduce this is to create a custom form with a managed_file element, upload a file, and then in your validate or submit function you execute:

// ...
$fid = $form_state->getValue('my_managed_file_element');
if (!empty($fid[0]) {
  File::load($fid[0])->delete();
}

The file will be erased from disk, as well as the file entity, but the record will still be present in the managed_file table, which will be used during garbage collection.

I was assuming that File::delete() would take care of everything, but I see that it uses file_unmanaged_delete() (source) to delete the file itself... Is it normal? Should I be deleting the file entity differently?

Version: 8.5.x-dev » 8.6.x-dev

Drupal 8.5.0-alpha1 will be released the week of January 17, 2018, which means new developments and disruptive changes should now be targeted against the 8.6.x-dev branch. For more information see the Drupal 8 minor version schedule and the Allowed changes during the Drupal 8 release cycle.

mrtndlmt’s picture

Thanks for the patch! Works for me on Drupal 8.4.4!

wiifm’s picture

Status: Needs work » Reviewed & tested by the community

With regards to #12, I can't think of any good reason why you would have a file writeable (so you could delete it), but not readable (like doing a chmod 222). You probably have larger concerns on your hands if this is the chmod value of any of your web server controlled files. So I think that is more of a theoretic issue.

Here is my experience with using this patch.

Before applying patch (stock Drupal core)

I see maybe a few hundred errors like this in the cron logs. These message repeat on every and all cron runs for the impacted sites. There is no easy way to fix this, and the error message is less than helpful.:

    Could not delete temporary file "public://2017-11/main05.jpg" during     [error]
    garbage collection

I believe the problem is exacerbated on large multisites where you clone sites, but for whatever reason do not clone the public files (so the managed_files table references files that never exist). This at least was the cause of the errors for me.

After the patch

Have applied the patch from #11. I see file files being cleaned up in the cron logs, along the lines of:

Temporary file "public://video_thumbnails/4780455931001.jpg" that was  [warning]
    deleted during garbage collection did not exist on the filesystem.

After a few cron runs, the list of files missing reduces to 0, and finally cron runs without producing any errors.

Marking as RTBC, as I feel the patch is well tested (has test cases), fixing the issue at hand, with no unwanted side effects on real life production systems.

larowlan’s picture

Issue summary: View changes
Status: Reviewed & tested by the community » Needs work

Thanks @wiifm for the detailed review, adding a review credit.

However #16 moved this to needs work because #12 and #14 were yet to be answered.

The same scenario exists, I'll update the IS