Entities sometimes get removed/unpublished unexpectedly on cron

That sounds pretty serious, so bumping to major.

Can you demonstrate this bug with an automated test? Because deleting the item from the clean list happens before validation. But there could be a case I hadn't thought of. Because in an other issue it is reported Feeds sometimes seems to clean more items than it should: #3068129: Issue Unpublishing non-existent nodes on Cron. (Theory not proven yet.)

From EntityProcessorBase::process():

// If the entity is an existing entity it must be removed from the clean
// list.
if ($existing_entity_id) {
  $clean_state->removeItem($existing_entity_id);
}
(...)
// Validate the entity.
$feed->dispatchEntityEvent(FeedsEvents::PROCESS_ENTITY_PREVALIDATE, $entity, $item);
$this->entityValidate($entity);

@damondt
I'm thankful if you manage to find the cause of the issue. :)

I suspect that #3068129: Issue Unpublishing non-existent nodes on Cron is exact the same issue. In there I say:

If there are two feeds updating the same content, I can imagine that the tracking of what needs to be cleaned can become a bit unpredictable. An imported item can only belong to one feed at the same time.

But veronicaSeveryn says:

I only have one feed updating these nodes and it's only triggered once a day, so, definitely, there can be no interference from another feed.

My suspicion is that $clean_state either isn't properly saved after processing an item - under certain circumstances - or it is sometimes not properly reloaded when processing the next item. There is a queue task for each item to be processed. And during cron runs, a limited amount of these queue tasks are processed. It's interesting to know that on a single cron run, if an item unexpectly stays on the clean list when the first queue task is being picked up, when the last queue task is being picked up or just somewhere in the middle.

@damondt
I don't see these kind of errors in the logs on a site where I'm using the "missing items" feature (and I remember having seen in the log lots of items getting unpublished and republished on the next import again). But maybe the last time the error occurred on that site is longer than two months ago.

A PDO Exception does disrupt the process, but Feeds does catch all exceptions in process(). So in theory, this should not prevent $clean_state from being saved.

I see that an exception may not be catched when it occurs while loading an existing entity, because Feeds didn't wrap that in a try-catch block.

// Delay building a new entity until necessary.
if ($existing_entity_id) {
  $entity = $this->storageController->load($existing_entity_id);
}

So could that be it? Does the exception occur during loading?

The last patch from #1803886: PDOException: Syntax error or access violation: 1305 SAVEPOINT savepoint_1 does not exist seems to want to ignore a specific PDO Exception and just let operations continue.

@damondt
That's a nice theory. I thought cron couldn't run another time while it was still running, but apparently that doesn't count for queues.

From \Drupal\Core\Cron:

  /**
   * {@inheritdoc}
   */
  public function run() {
    // Allow execution to continue even if the request gets cancelled.
    @ignore_user_abort(TRUE);

    // Force the current user to anonymous to ensure consistent permissions on
    // cron runs.
    $this->accountSwitcher->switchTo(new AnonymousUserSession());

    // Try to allocate enough time to run all the hook_cron implementations.
    Environment::setTimeLimit(240);

    $return = FALSE;

    // Try to acquire cron lock.
    if (!$this->lock->acquire('cron', 900.0)) {
      // Cron is still running normally.
      $this->logger->warning('Attempting to re-run cron while it is already running.');
    }
    else {
      $this->invokeCronHandlers();
      $this->setCronLastTime();

      // Release cron lock.
      $this->lock->release('cron');

      // Return TRUE so other functions can check if it did run successfully
      $return = TRUE;
    }

    // Process cron queues.
    $this->processQueues();

    // Restore the user.
    $this->accountSwitcher->switchBack();

    return $return;
  }

The cron lock is released before queues are processed.

@damondt
In #3068129: Issue Unpublishing non-existent nodes on Cron, @veronicaSeveryn says that it can also happen even if cron runs only once a day.

But nevertheless, it would be good to prevent $clean_state from missing things if two queue tasks are run simultaneously. Thinking how we could write a test for this case: I think we would need to start two asynchronous queue tasks and then wait for both to finish. Then check for the expected contents for $clean_state.

Another way of testing this is as follows:

• In a test, manually perform a queue task.
• Respond to one of the Feeds events and in there start a task from the same queue.

What I proposed in #10 is also possible, but requires juggling with sleep() calls. So what I propose here is definitely simpler, but it covers slightly less from the real situation.

Ran into a similar problem which @damondt pointed me to this issue. I've continually had issues with a rather large import intermittently deleting items that were actually in the feed source data. I suspected this was due to feed importers overlapping or the queue not finishing properly. On an importer of ~4000 entries we were seeing anywhere from 30-90 items being marked for deletion when they were in the feed. These items were always in a group in the source data but the importer would continue on and reported no errors. What ultimately resolved our problem was setting up a scheduled job in acquia which seems to more reliably process the import.

@damondt
We can also just adjust the title of this issue and update the issue summary, as this issue contains useful information.

Or, alternatively, we could continue in #3068129: Issue Unpublishing non-existent nodes on Cron, I think it's the same problem.

@damondt
Slightly related to this issue: I've been working to refactor the four different import methods (import all at once, batch in UI, cron import/queue, push import) to make them all operate in the same way. For example, switching user accounts only happened during cron imports. Perhaps this issue is easier to tackle after that refactoring has been finalized. Maybe you want to review the refactoring globally?
#2811429: Switch to feed owner during manual import.

I'm seeing this on a site as well. Only 1 feed running on the entire site, once per day and once per hour has led to the same results. I random amount ~50-100 being 'cleaned' then reimported later.

Retitling as validation has nothing to do with the issue.

Had done the retitling in the "Commit message" field instead of in the "Title" field :D.

I've worked on a test for this issue today.

The test implements what I proposed in #11:

• In a test, manually perform a queue task.
• Respond to one of the Feeds events and in there start a task from the same queue.

This patch could fix the issue.

The list of items to clean is moved to the database. This should fix the issue of having outdated lists overwrite newer lists, because the entire clean list is managed in the database instead of in a serialized array. I'm not sure if this would cause issues with a huge dataset though (when there are millions of items to import).

I did create the patch on top of #2811429: Switch to feed owner during manual import., so there is a chance that the patch won't apply properly.

Lots of the kernel tests are missing the "feeds_clean_list" table. Let's add that table for all tests and see if that fixes the test failures.
Also fixed two coding standard issues.

This adds dependency injection for the CleanState class. Hopefully, this fixes the remaining test failures.

The patch in #23 was based on the latest patch in #2811429: Switch to feed owner during manual import..

This one is based on the latest 8.x-3.x-dev.

#2811429: Switch to feed owner during manual import. was committed, which makes the patch in #23 the one to test now and patch #24 can be ignored.

After doing a self-review, I think that when $feed->clearStates() is called that the clean list in the database need to be cleaned up. Now this happens on the next import (see CleanState::setList()). But if you decide to stop importing a feed, you'll have some redundant rows in the database table "feeds_clean_list".

I inspected the code again and did a manual test where nodes got cleaned on an import. It appeared that the table "feeds_clean_list" became empty after cleaning was done. This is because when cleaning each item, the corresponding record is already removed from the table. From CleanState::nextEntity():

// Claim the item, remove it from the list.
$this->removeItem($entity_id);

Anyway, it would be good to clean up the clean list anyway when calling $feed->clearStates().

Also, orphaned items can still exist when an import ends abruptly. $feed->clearStates() won't be reached when an import fails with a fatal error. So I think an other moment for cleaning up redundant rows is when deleting the feed.

Patch attached with additional tests.

I looked through the code one more time, didn't have any concerns anymore.

Committed #26.