Add delay on entity re-ingestion on failed attempt #298

lagoan · 2023-01-30T18:14:34Z

When an entity fails to be deposited, PMPY would only wait for the minimum age to retry to ingest the entity. This creates the problem where we don't let the problem be fixed and we flood the logs with information that is no longer useful.

This change doubles the time of each attempt to give space for the problems to be fixed. There are 3 configuration parameters added:

ingestion_prefix: The prefix used for Redis keys storing the failed attempt count - Default value of - Default value of prod:pmpy_ingest_attempt:
ingestion_attempts: The max number of re-ingestion attempts - Default value of 15
first_failed_wait: The time to add at the beginning which will be double every retry - Default value of 10

The default values will keep retrying for around a week and drop the entity for ingestion.

This is related to issue #297.

When an entity failed to be deposited, PMPY would only wait the minimum age to retry to ingest the entity. This creates the problem where we don't let the problem to be fixed and we flood the logs with information that is no longer useful. This change doubles the time of each attempt to give space for the problems to be fixed. There are 3 configuration parameters added: - ingestion_prefix : The prefix used for redis keys storing the failed attempt count - Default value of - Default value of `prod:pmpy_ingest_attempt:` - ingestion_attempts : The max number of re-ingestion attempts - Default value of `15` - first_failed_wait : The time to add at the beginning which will be double every retry - Default value of `10` The default values will keep retrying for around a week and will drop the entity for ingestion after that. This is related to issue [#297](#297).

ConnorSheremeta · 2023-01-30T21:50:15Z

spec/pushmi_pullyu/cli_spec.rb

+              time_now = Time.now.to_i
+              _readded_entity, readded_entity_score = redis.zrange(PushmiPullyu.options[:queue_name],
+                                                                   0, 0, with_scores: true).first
+              deposit_attempt = redis.get(attempt_key).to_i


Might be nice to assert that redis.get(attempt_key).to_i equals deposit_attempt + 1 here as it cannot be assumed necessarily from the test side that this will always increment

ConnorSheremeta · 2023-01-30T22:25:06Z

lib/pushmi_pullyu/preservation_queue.rb

+  def self.extra_wait_time(deposit_attempt)
+    extra = 0
+    deposit_attempt.times do |n|
+      extra += (2**n) * PushmiPullyu.options[:first_failed_wait]
    end
+    extra
  end


This doesn't appear to match the stated specifications of: "doubles the time of each attempt"

With a PushmiPullyu.options[:first_failed_wait] of 10 it appears that this is the added wait time of each attempt:

0 10 30 70 150 310 630 1270 2550 5110

If doubling added wait on each attempt starting with first_failed_wait is what we're trying to accomplish it looks like this would give that:

def self.extra_wait_time(deposit_attempt) return 0 if deposit_attempt == 0 (2**(deposit_attempt - 1)) * PushmiPullyu.options[:first_failed_wait] end

The numbers vary slightly so this is a small nit in reality

You are right!

This code should work:

(2**deposit_attempt) * PushmiPullyu.options[:first_failed_wait]

Will make the changes

ConnorSheremeta · 2023-01-30T22:29:04Z

lib/pushmi_pullyu/cli.rb

+      o.on('-i', '--ingestion_prefix PREFIX',
+           'Prefix for keys used in counting the number of failed ingestion attempts') do |prefix|
+        opts[:ingestion_prefix] = prefix
+      end
+
+      o.on('-x', '--ingestion_attempts NUMBER', Integer,
+           'Max number of attempts to try ingesting an entity') do |ingestion_attempts|
+        opts[:ingestion_attempts] = ingestion_attempts
+      end
+
+      o.on('-f', '--first_failed_wait NUMBER', Integer,
+           'Time in seconds to wait after first failed deposit. Time will double every failed attempt') do |failed_wait|
+        opts[:first_failed_wait] = failed_wait
+      end
+


Probably worth adding these new options to the README

They are there, do let me know if I can clarify it though.

https://github.com/ualbertalib/pushmi_pullyu/pull/298/files#diff-b335630551682c19a781afebcf4d07bf978fb1f8ac04c6bf87428ed5106870f5

ConnorSheremeta

LGTM. I was curious if items that fail should be kept track of? Not sure if there's already a way to verify which items didn't succeed or if we even care to keep track of this.

lagoan · 2023-01-31T18:36:20Z

lib/pushmi_pullyu/cli.rb

+      begin
+        queue.add_entity_in_timeframe(entity)
+      rescue MaxDepositAttemptsReached => e
+        log_exception(e)
+      end


This bit of code will log when an entity reaches the max number of attempts for ingestion.

@ConnorSheremeta do you think this would be enough to keep track of the failed items? It would mean going through the logs though, not sure if this is the best approach. Always open to ideas!

Filtering through the logs could suffice although it may not be ideal, I suppose these failures could be logged to another file but that may not be worth doing as this information can be filtered as needed

pgwillia

pgwillia · 2023-02-02T18:47:12Z

lib/pushmi_pullyu/cli.rb

-      # jupiter is submitting the entries to reddis in a hash format using fat arrows. We need to change them to colons
-      # in order to parse them correctly from json
-      entity = JSON.parse(entity_json.gsub('=>', ':'), { symbolize_names: true })


Is this no longer an issue?

To my understanding, this was an old error where the items were being added to the queue in an incorrect manner that added the fat arrows. The new versions of jupiter and pmpy will be adding correct json.

pgwillia · 2023-02-02T18:52:47Z

lib/pushmi_pullyu/preservation_queue.rb

    @redis.with do |connection|
-      connection.zadd @queue_name, Time.now.to_f, entity_json
+      # separate information for priority information and queue
+      deposit_attempt = connection.incr entity_attempts_key


What would happen if we deploy this and there are items already in the queue which wouldn't have an entity_attempts_key?

from https://devdocs.io/redis/incr

If the key does not exist, it is set to 0 before performing the operation.

That is correct, the normal behaviour would continue

pgwillia · 2023-02-02T19:05:27Z

spec/pushmi_pullyu/preservation_queue_spec.rb

-      redis.zadd 'test:pmpy_queue', 1, 'noid1'
-      redis.zadd 'test:pmpy_queue', 3, 'noid3'
-      redis.zadd 'test:pmpy_queue', 4, 'noid2'


Are noid1, noid2, and noid3 still used or defined somewhere?

These values where just used for this test.

pgwillia · 2023-02-02T19:11:58Z

lib/pushmi_pullyu/preservation_queue.rb

    end
  end

+  def self.extra_wait_time(deposit_attempt)
+    (2**deposit_attempt) * PushmiPullyu.options[:first_failed_wait]


lagoan requested review from ConnorSheremeta, henryzhang87, pgwillia and piyapongch as code owners January 30, 2023 18:14

lagoan mentioned this pull request Jan 30, 2023

Add ingestion attempt communication with PMPY ualbertalib/jupiter#3049

Merged

ConnorSheremeta reviewed Jan 30, 2023

View reviewed changes

Addressed PR suggestions

2f361f5

ConnorSheremeta approved these changes Jan 31, 2023

View reviewed changes

lagoan commented Jan 31, 2023

View reviewed changes

lagoan merged commit a1f46d4 into master Jan 31, 2023

lagoan deleted the add/entity_ingestion_attempts_priority branch January 31, 2023 21:19

pgwillia reviewed Feb 2, 2023

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add delay on entity re-ingestion on failed attempt #298

Add delay on entity re-ingestion on failed attempt #298

lagoan commented Jan 30, 2023

ConnorSheremeta Jan 30, 2023

ConnorSheremeta Jan 30, 2023

lagoan Jan 31, 2023

ConnorSheremeta Jan 30, 2023

lagoan Jan 31, 2023

ConnorSheremeta left a comment

lagoan Jan 31, 2023

lagoan Jan 31, 2023

ConnorSheremeta Jan 31, 2023

pgwillia left a comment

pgwillia Feb 2, 2023

lagoan Feb 2, 2023

pgwillia Feb 2, 2023

pgwillia Feb 2, 2023

lagoan Feb 2, 2023

pgwillia Feb 2, 2023

lagoan Feb 2, 2023

pgwillia Feb 2, 2023

Add delay on entity re-ingestion on failed attempt #298

Add delay on entity re-ingestion on failed attempt #298

Conversation

lagoan commented Jan 30, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ConnorSheremeta left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pgwillia left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment