Problem/Motivation

Under certain circumstances Feeds seems to randomly delete or unpublish previously imported items. This can happen when two concurrent imports are happening for the same feed. Feeds then looses track of which items it has seen. The "unpublish/delete" feature works as follows:

  1. At the start of an import, a list of all previous items is generated and saved in the feeds_clean_list table.
  2. After processing each imported item, the reference to that item is removed from the list.
  3. At the end of an import all remaining items on the list are "cleaned". This can mean these get unpublished, deleted or some other action (each action plugin that doesn't require interaction nor configuration can be used).

In the event that two imports for the same feed are active, the clean list gets messed up. While the first import is at a certain point, the second import resets the list, causing the first import to clean the items that got back on the list.

Three causes have been detected for having concurrent imports:

  1. An EmptyFeedException did not got properly catched

    This is resolved in #3261348: EmptyFeedException filling up log. The bug was that when a source returned the HTTP status code 304 (document unchanged), the import got marked as finished, but the import task remained on the queue.

  2. A feed import gets automatically unlocked after 12 hours

    When an import does not complete within 12 hours, the feed gets unlocked and an other import can start while the first one is still running. This is more likely to happen if periodic import has been configured for the feed type. This cause is the one to address here.

  3. A feed gets unlocked manually

    In the user interface you have the option to unlock a feed that is running. If an other import is still active, you potentially can get two concurrent imports. I'd like to fix this issue partly later by clearing the queue for the feed in question. This can be handled in an other issue.

Reasons an import does not complete in 12 hours

  • Cron doesn't run often (for example: only a few times a day);
  • There is (sometimes) a gap of more than 12 hours between two cron runs;
  • The source to fetch is unavailable for some time. This also causes Feeds to retry the fetch over and over again for which I opened #3277999: Add DelayedRequeueException feature to feeds queue - D9.1.
  • (not verified) The import ends abruptly because of a fatal error (maybe a syntax error in an other module?). The import task then remains on the queue, and I think that it will be picked up again as soon as the error is resolved. It might be useful to test this scenario.

Steps to reproduce

  1. Create a feed type. On the processor settings, set "Previously imported items" to for example "Delete" or "Unpublish content item".
  2. Optionally configure periodic import (issue is more likely to happen when you do)
  3. Use a source that takes multiple cron runs to complete.
  4. Start a feed import. Wait until it completes. (When doing an import for the first time, Feeds has zero items to put on the clean list.)
  5. Start a new feed import. (Feeds will put some items on the clean list.)
  6. When that import runs for a while, unlock the feed and start another import. The second import must start before the other is completed in order to experience the issue.

As said above, the issue to tackle here is to prevent two concurrent imports for the case an import takes longer than 12 hours to complete.

Proposed resolution

Instead of automatically unlocking the feed, I propose the following:

  • Make the lock lifetime configurable (mainly for being able to create test coverage for this issue).
  • After the lock lifetime exceeded, detect if an import is still running. If so, extend the lock lifetime. Otherwise, unlock. I think we need to use our own Feeds lock service for this (that extends \Drupal\Core\Lock\DatabaseLockBackend).

Detecting an import

Detecting if an import is still running can be challenging. Right now, there is no easy way to see if a task for a certain feed is on the queue. I hope that becomes easier once #2978490: Optimize Feeds queue is fixed. Then we could query the queue table for something like data LIKE '%"fid";i:[feed-id]%' where [feed-id] is the ID of the feed.
A feed import can also happen to run in the UI. Not sure yet how to detect that. This also looks less likely to me to take more than 12 hours. So we could decide to not cover that scenario.

Remaining tasks

  • Make lock lifetime configurable DONE
  • Add test coverage for the bug DONE
  • Create a new lock service (based on \Drupal\Core\Lock\DatabaseLockBackend). DONE
  • Think of ways to detect if an import is still running (one being querying the queue table) DONE
  • Upon exceeding the lock lifetime, extend it if an import is still running. DONE
  • Add a database update for setting the default lock lifetime.

User interface changes

Maybe a settings page for configuring the lock lifetime. This could also be made a hidden setting, however.

API changes

  • A new lock service is added
  • Methods for detecting an import are added (not sure to which class yet)

Data model changes

  • A configuration schema is added for Feeds settings
  • Default configuration for the lock lifetime is added to a database update.

Original report by mxmilkiib

I was on alpha7, now dev, and I've got items going missing from https://libreav.org/river with the Items count saying 10, but the Items tab table displaying only 8 entries, and such like, and having to reimport to make things turn up, only for them to go again. I set cron to a week, and it still happened, when other feeds get imported manually, but not all items have been affected, apparently mostly newer ones. I have tried changing who owns the feed items but no difference (actually I'm not sure the right user showed up in the log). Expire is set to never. Not sure how to reproduce from scratch.

CommentFileSizeAuthor
#15 Screen Shot 2022-05-12 at 1.57.23 PM.png578.61 KBandileco

Issue fork feeds-3193610

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

About issue forks

Comments

mxmilkiib created an issue. See original summary.

mxmilkiib’s picture

mxmilkiib commented
Issue summary: View changes
megachriz’s picture

megachriz
Primary language Dutch
commented

On a site, I sometimes too notice that items go missing after doing an import. I think it has something to do with the setting "Previously imported items" on the processor settings. I haven't found so far what is causing it. What I do notice is that seems to be more likely to occur when an import has happened for a while (for example: one week). This happens mostly in my development environment, where I don't run cron regularly. But it has occurred on a production environment as well, but only during a time when due to a bug in a custom module the import of a feed got halted for a few days.

My hope is that after I finish #2907721: Log items that failed to import, I'm able to get a better understanding of what's causing items going missing. I do suspect currently that the bug in my case is in custom code. I have the suspicion that custom code is overwriting the file that is being imported while the import is still ongoing.

mxmilkiib’s picture

mxmilkiib commented

I have 'Previously imported items' set to Keep. I also have 'Always download' turned on due to #3155929: Http Fetcher receiving 304s Do not clear out their queue items..

I have had great trouble trying to pin down any form of pattern as to the removals. In one case I reimported one to return an item, and one item from another went, so I reimported that other feed and the original ones item went again. This repeated for 3 times. In other cases some other items (the same ones repeatedly) went after an hour or so when I was reimporting another feed. Others haven't budged. Big whack-a-mole vibes! This happens to new and historic entries, I just mostly notice the new ones. It came to a head last night as I had an IRC channel full of devs saying "oh, my release went again!" whilst we waited for a YouTuber to start a live stream on a quarterly community release event. I turned cron off and have reimported enough that the pile of sand hasn't fallen down much again.

megachriz’s picture

megachriz
Primary language Dutch
commented

When the source is downloaded via HTTP, it gets temporary stored in the Drupal temporary directory. Maybe it doesn't stay there long enough to complete the import? My hope is that when #2912130: Missing temporary files in load balanced environments (stable release blocker) gets fixed, issues like this are less likely to occur.

mxmilkiib’s picture

mxmilkiib commented

FWIW, I realise now that first the feed content items disappear (either all of them or just some of them), but the Items imported number stays the same, then later the Items imported number drops to 0.

megachriz’s picture

megachriz
Primary language Dutch
commented

The amount of imported items is only updated when the feed entity gets saved, not when items are deleted outside of Feeds. That can be seen as a minor bug. See also #3182996: The "Items imported" count is not re-calculated when imported items are deleted.

mxmilkiib’s picture

mxmilkiib commented

I think this may well be because, even though the owner was set to a user created specifically for feeds (with the right permissions), feed items sometimes just get created as anon, and that role doesn't have the permission to set the body text format that is being used.

mxmilkiib’s picture

mxmilkiib commented

I tried setting "Owner: Feed author", which would be my admin account, but the items are still created by 'Anon'

Edit; I gave permission to Anon role for the text format used and now new items are apparently not going away. The differing user used for items retrieved a while back was what made those remain.

Edit2; I think the Anon items, even with the text format permission for Anon, are still going after being imported.

mxmilkiib’s picture

mxmilkiib commented

On 8.x-3.0-alpha10 atm and the items correctly get imported as the feed author now.

But I manually imported a feed that had 1 entry an hour ago, and that item has already gone from the Items tab.

N.b. when feeds are reimported again, the entries have the same NID as before. (Edit: I don't think this is the case anymore; the irc bot links to releases with their titles, but then the title is different on the release page when checked.)

Edit: I think this is creating a massive churn of a few hundred feed entry entities being created and (partially?) deleted with every cron run, fueling the creation of a rather large number of db binlog files. I think possibly maybe that when the VPS runs out of space, this triggers the 1969 feed reimport dates. I'm not really wanting to test that circumstance directly again though ;)

mxmilkiib’s picture

mxmilkiib commented

Possibly related to https://www.drupal.org/project/drupal/issues/3198890

mxmilkiib’s picture

mxmilkiib commented

I tried https://www.drupal.org/project/feeds/issues/2912130#comment-13898889 feeds--temporary-files-handling--2912130-73-D8.patch but things still disappear.

megachriz’s picture

megachriz
Primary language Dutch
commented

I suspect that the following code in feeds_cron() in feeds.module has something to do with it:

  // Delete queued timestamp after 12 hours assuming the update has failed.
  $ids = \Drupal::entityQuery('feeds_feed')
    ->condition('queued', \Drupal::time()->getRequestTime() - (3600 * 12), '<')
    ->execute();

But I haven't found the time yet to investigate that.

The above code could imply that it triggers simultaneous imports. And when two imports for the same feed run at the same time, this will mess up the data of what needs to be unpublished/deleted near the end of the import process.

mxmilkiib’s picture

mxmilkiib commented
Priority: Normal » Major

Re data loss

andileco’s picture

andileco commented
StatusFileSize
new Screen Shot 2022-05-12 at 1.57.23 PM.png578.61 KB

@MegaChriz, I have a Storage type (from the Storage Entities module) that pulls in data via several different feeds. I believe that you are correct in #13 when you say there can be errors when two feeds are running simultaneously on the same entity. Here's the errors that I got:

Error log showing items that failed to import because 'modified by another user'

megachriz’s picture

megachriz
Primary language Dutch
commented
Issue summary: View changes

I've found out three possible causes for this issue.

The first one is that an EmptyFeedException did not got properly catched. This exception is thrown when a source returned the HTTP status code 304 (document unchanged). In this case, the import got marked as finished but the import task remained on the queue. This issue is resolved in #3261348: EmptyFeedException filling up log. This fix will be available in Feeds 8.x-3.0-beta2 which I plan to release in a few weeks (it is already available in the dev version).

The second cause, and the one to handle here is that a feed gets automatically unlocked after 12 hours - even when an import has not been completed yet. It may not happen often that a feed import does not complete within 12 hours, but I know from experience that it can. This can happen for example when:

  • Cron doesn't run often (for example: only a few times a day);
  • There is (sometimes) a gap of more than 12 hours between two cron runs;
  • The source to fetch is unavailable for some time. This also causes Feeds to retry the fetch over and over again for which I opened #3277999: Add DelayedRequeueException feature to feeds queue - D9.1.
  • (not verified) The import ends abruptly because of a fatal error (maybe a syntax error in an other module?). The import task then remains on the queue, and I think that it will be picked up again as soon as the error is resolved. It might be useful to test this scenario.

The third cause is when you manually unlock a feed and start another feed import while one is still running.

MegaChriz opened merge request !72

megachriz’s picture

megachriz
Primary language Dutch
commented
Status: Active » Needs work

There is a test, but no fix yet.

megachriz’s picture

megachriz
Primary language Dutch
commented
Issue summary: View changes
Status: Needs work » Needs review

This is ready for testing. The only thing left to add is a database update for setting the default lock lifetime.

Best way to test this:

  1. Setup two sites that import the same content.
  2. Use the same version of Feeds on both sites, but apply the code from this issue on only one of them.
  3. Make sure that the content to import is large enough that usually more than one cron run is needed to import it. Also make sure that the content changes often.
  4. Configure periodic import on the feed types.
  5. Configure feed types to unpublish or delete previously imported items that no longer are in the source.
  6. Configure cron to run only twice a day (or less). If you are however sure that content takes more than 2 cron runs to complete, you can configure it to run more often: max number of cron runs a day ≈ average amount of cron runs needed to complete a single import.
  7. After a few days, check the imported items on the site. If items are missing on the site without the code from this issue, but these are not missing on the site with this code, then I assume this issue to be fixed.

  • MegaChriz committed 873eb8f on 8.x-3.x 
    Issue #3193610 by MegaChriz: Fixed items getting unpublished/deleted...
megachriz’s picture

megachriz
Primary language Dutch
commented
Status: Needs review » Fixed

I tested the code for several weeks using the plan written on #19. This showed me that on site A (fix applied) not a single item got cleaned unexpectedly and on site B (no fix applied) dozens of items got cleaned that were not supposed to get cleaned. I'm therefore quite confident that this fixes the issue.

The code is merged! Now moving to the next related one: #3132198: Clean queue tasks when unlocking a feed to prevent potential data loss.

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.