DataCorrupted: invalid page in block of relation base

sirajhassan · November 27, 2023, 9:14am

Hi All,

The following error appears in pillowtop-case-pillow log file, and unable to see the error from the pg_log.

Is the issue related to the PostgreSQL database?

Thank you,

Starting pillow <class 'pillowtop.pillow.interface.ConstructedPillow'>.run()
Traceback (most recent call last):
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 175, in maybe_not_found
    yield
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 99, in get
    resp = self._s3_bucket().Object(key).get()
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/boto3/resources/factory.py", line 580, in do_action
    response = action(self, *args, **kwargs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/boto3/resources/action.py", line 88, in __call__
    response = getattr(parent.meta.client, operation_name)(*args, **params)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/botocore/client.py", line 514, in _api_call
    return self._make_api_call(operation_name, kwargs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/botocore/client.py", line 938, in _make_api_call
    raise error_class(parsed_response, operation_name)
botocore.errorfactory.NoSuchKey: An error occurred (NoSuchKey) when calling the GetObject operation: The specified key does not exist.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 696, in get_xml
    return self.get_attachment('form.xml')
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/attachment.py", line 259, in get_attachment
    with attachment.open() as content:
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/models.py", line 107, in open
    return db.get(meta=self)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/dimagi/utils/retry.py", line 31, in retry
    return func(*args, **kw)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 99, in get
    resp = self._s3_bucket().Object(key).get()
  File "/usr/lib/python3.9/contextlib.py", line 137, in __exit__
    self.gen.throw(typ, value, traceback)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 181, in maybe_not_found
    raise throw
corehq.blobs.exceptions.NotFound: 7996095027ca4224a843b94df20c4036

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 221, in _batch_process_with_error_handling
    retry_changes, change_exceptions = processor.process_changes_chunk(changes_chunk)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/pillow.py", line 433, in process_changes_chunk
    failed, exceptions = self._process_chunk_for_domain(domain, changes_chunk)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/pillow.py", line 458, in _process_chunk_for_domain
    if adapter.config.filter(doc, eval_context):
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/models.py", line 378, in filter
    return filter_fn(document, eval_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in __call__
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in <genexpr>
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 61, in __call__
    return any(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 61, in <genexpr>
    return any(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in __call__
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in <genexpr>
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 94, in __call__
    self.expression(item, evaluation_context), self.reference_expression(item, evaluation_context))
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 658, in __call__
    argument = self._argument_expression(item, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 195, in __call__
    items = _evaluate_items_expression(self._items_expression, doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 18, in _evaluate_items_expression
    result = itemx_ex(doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 285, in __call__
    items = _evaluate_items_expression(self._items_expression, doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 18, in _evaluate_items_expression
    result = itemx_ex(doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 69, in __call__
    items = _evaluate_items_expression(self._items_expression, doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 18, in _evaluate_items_expression
    result = itemx_ex(doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 853, in __call__
    return self._get_forms(case_id, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 866, in _get_forms
    xforms = [self._get_form_json(f, evaluation_context) for f in xforms if f.domain == domain]
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 866, in <listcomp>
    xforms = [self._get_form_json(f, evaluation_context) for f in xforms if f.domain == domain]
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 881, in _get_form_json
    form_json = form.to_json()
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 666, in to_json
    data = dict(serializer.data)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/serializers.py", line 555, in data
    ret = super().data
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/serializers.py", line 253, in data
    self._data = self.to_representation(self.instance)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/serializers.py", line 509, in to_representation
    attribute = field.get_attribute(instance)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/fields.py", line 457, in get_attribute
    return get_attribute(instance, self.source_attrs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/fields.py", line 97, in get_attribute
    instance = getattr(instance, attr)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/memoized.py", line 20, in _memoized
    cache[key] = value = fn(*args, **kwargs)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 614, in form_data
    xml = self.get_xml()
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/memoized.py", line 20, in _memoized
    cache[key] = value = fn(*args, **kwargs)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 698, in get_xml
    raise MissingFormXml(self.form_id)
corehq.form_processor.exceptions.MissingFormXml: cc404ae1-366e-4d4f-9006-51a3a255b188

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 175, in maybe_not_found
    yield
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 99, in get
    resp = self._s3_bucket().Object(key).get()
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/boto3/resources/factory.py", line 580, in do_action
    response = action(self, *args, **kwargs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/boto3/resources/action.py", line 88, in __call__
    response = getattr(parent.meta.client, operation_name)(*args, **params)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/botocore/client.py", line 514, in _api_call
    return self._make_api_call(operation_name, kwargs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/botocore/client.py", line 938, in _make_api_call
    raise error_class(parsed_response, operation_name)
botocore.errorfactory.NoSuchKey: An error occurred (NoSuchKey) when calling the GetObject operation: The specified key does not exist.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 696, in get_xml
    return self.get_attachment('form.xml')
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/attachment.py", line 259, in get_attachment
    with attachment.open() as content:
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/models.py", line 107, in open
    return db.get(meta=self)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/dimagi/utils/retry.py", line 31, in retry
    return func(*args, **kw)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 99, in get
    resp = self._s3_bucket().Object(key).get()
  File "/usr/lib/python3.9/contextlib.py", line 137, in __exit__
    self.gen.throw(typ, value, traceback)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/blobs/s3db.py", line 181, in maybe_not_found
    raise throw
corehq.blobs.exceptions.NotFound: 7996095027ca4224a843b94df20c4036

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 254, in process_with_error_handling
    processor.process_change(change)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/pillow.py", line 556, in process_change
    if table.config.filter(doc, eval_context):
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/models.py", line 378, in filter
    return filter_fn(document, eval_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in __call__
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in <genexpr>
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 61, in __call__
    return any(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 61, in <genexpr>
    return any(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in __call__
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 44, in <genexpr>
    return all(_filter(item, evaluation_context) for _filter in self.filters)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/filters/__init__.py", line 94, in __call__
    self.expression(item, evaluation_context), self.reference_expression(item, evaluation_context))
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 658, in __call__
    argument = self._argument_expression(item, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 195, in __call__
    items = _evaluate_items_expression(self._items_expression, doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 18, in _evaluate_items_expression
    result = itemx_ex(doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 285, in __call__
    items = _evaluate_items_expression(self._items_expression, doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 18, in _evaluate_items_expression
    result = itemx_ex(doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 69, in __call__
    items = _evaluate_items_expression(self._items_expression, doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/list_specs.py", line 18, in _evaluate_items_expression
    result = itemx_ex(doc, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 853, in __call__
    return self._get_forms(case_id, evaluation_context)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 866, in _get_forms
    xforms = [self._get_form_json(f, evaluation_context) for f in xforms if f.domain == domain]
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 866, in <listcomp>
    xforms = [self._get_form_json(f, evaluation_context) for f in xforms if f.domain == domain]
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/apps/userreports/expressions/specs.py", line 881, in _get_form_json
    form_json = form.to_json()
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 666, in to_json
    data = dict(serializer.data)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/serializers.py", line 555, in data
    ret = super().data
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/serializers.py", line 253, in data
    self._data = self.to_representation(self.instance)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/serializers.py", line 509, in to_representation
    attribute = field.get_attribute(instance)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/fields.py", line 457, in get_attribute
    return get_attribute(instance, self.source_attrs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/rest_framework/fields.py", line 97, in get_attribute
    instance = getattr(instance, attr)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/memoized.py", line 20, in _memoized
    cache[key] = value = fn(*args, **kwargs)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 614, in form_data
    xml = self.get_xml()
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/memoized.py", line 20, in _memoized
    cache[key] = value = fn(*args, **kwargs)
  File "/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/form_processor/models/forms.py", line 698, in get_xml
    raise MissingFormXml(self.form_id)
corehq.form_processor.exceptions.MissingFormXml: cc404ae1-366e-4d4f-9006-51a3a255b188

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
psycopg2.errors.DataCorrupted: invalid page in block 24080225 of relation base/16412/20068


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/cchq/www/echis/current/manage.py", line 190, in <module>
    main()
  File "/home/cchq/www/echis/current/manage.py", line 48, in main
    execute_from_command_line(sys.argv)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/core/management/__init__.py", line 419, in execute_from_command_line
    utility.execute()
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/core/management/__init__.py", line 413, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/core/management/base.py", line 354, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/core/management/base.py", line 398, in execute
    output = self.handle(*args, **options)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/management/commands/run_ptop.py", line 137, in handle
    start_pillow(pillow)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/run_pillowtop.py", line 39, in start_pillow
    pillow_instance.run()
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 116, in run
    self.process_changes(since=self.get_last_checkpoint_sequence(), forever=True)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 175, in process_changes
    self._batch_process_with_error_handling(changes_chunk)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 234, in _batch_process_with_error_handling
    reprocess_serially(changes_chunk, processor)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 211, in reprocess_serially
    self.process_with_error_handling(change, processor)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 261, in process_with_error_handling
    handle_pillow_error(self, change, ex)
  File "/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py", line 511, in handle_pillow_error
    error.save()
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/models/base.py", line 739, in save
    self.save_base(using=using, force_insert=force_insert,
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/models/base.py", line 776, in save_base
    updated = self._save_table(
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/models/base.py", line 858, in _save_table
    updated = self._do_update(base_qs, using, pk_val, values, update_fields,
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/models/base.py", line 912, in _do_update
    return filtered._update(values) > 0
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/models/query.py", line 802, in _update
    return query.get_compiler(self.db).execute_sql(CURSOR)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/models/sql/compiler.py", line 1559, in execute_sql
    cursor = super().execute_sql(result_type)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/models/sql/compiler.py", line 1175, in execute_sql
    cursor.execute(sql, params)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/sentry_sdk/integrations/django/__init__.py", line 582, in execute
    return real_execute(self, sql, params)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/backends/utils.py", line 66, in execute
    return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/backends/utils.py", line 75, in _execute_with_wrappers
    return executor(sql, params, many, context)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/utils.py", line 90, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
django.db.utils.InternalError: invalid page in block 24080225 of relation base/16412/20068

sirajhassan · November 27, 2023, 12:13pm

Found an error in pg_log:

2023-11-27 07:28:43.558 GMT,"commcarehq","commcarehq",169645,"127.0.0.1:44990",65643cc6.296ad,138,"INSERT",2023-11-27 06:52:54 GMT,691/5327,2743528444,ERROR,XX001,"invalid page in block 24080225 of relation base/16412/20068",,,,,,"INSERT INTO ""pillow_retry_pillowerror"" (""doc_id"", ""pillow"", ""date_created"", ""date_last_attempt"", ""date_next_attempt"", ""total_attempts"", ""current_attempt"", ""error_type"", ""error_traceback"", ""change"", ""change_metadata"") VALUES ('3502d374-f25a-402d-b573-d51388680374', 'xform-pillow', '2023-10-20T11:48:36.069120'::timestamp, '2023-11-27T07:28:43.553159'::timestamp, NULL, 4, 4, 'corehq.form_processor.exceptions.MissingFormXml', 'Unable to get document with ID ''3502d374-f25a-402d-b573-d51388680374'' from document store DocStoreLoadTracker(<corehq.form_processor.document_stores.FormDocumentStore object at 0x7f8be6533d30>)

File ""/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/pillow/interface.py"", line 254, in process_with_error_handling
processor.process_change(change)
File ""/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/processors/elastic.py"", line 90, in process_change
doc = change.get_document()
File ""/home/cchq/www/echis/releases/2023-11-26_18.40/corehq/sql_db/util.py"", line 225, in _inner
return fn(*args, **kwargs)
File ""/home/cchq/www/echis/current/corehq/ex-submodules/pillowtop/feed/interface.py"", line 92, in get_document
raise err.class(
', '{""id"":""3502d374-f25a-402d-b573-d51388680374"",""seq"":12528986,""doc"":null,""deleted"":false}', '{""document_id"":""3502d374-f25a-402d-b573-d51388680374"",""data_source_type"":""sql"",""data_source_name"":""form-sql"",""document_type"":""XFormInstance"",""document_subtype"":""http://openrosa.org/formdesigner/1CB08D86-30C4-4E02-9E70-0C7093DF575D"",""domain"":""fmoh-echis"",""is_deletion"":false,""document_rev"":null,""publish_timestamp"":""2023-11-07T20:42:30.752238Z"",""attempts"":4,""original_publication_datetime"":""2023-10-20T11:48:36.069120Z""}') RETURNING ""pillow_retry_pillowerror"".""id""",,,"","client backend",,6840366466704529347

smittieC · November 28, 2023, 7:15am

Hi @sirajhassan

Looking at these lines:

botocore.errorfactory.NoSuchKey: An error occurred (NoSuchKey) when calling the GetObject operation: The specified key does not exist.

corehq.form_processor.exceptions.MissingFormXml: cc404ae1-366e-4d4f-9006-51a3a255b188

it seems like the form has an attachment that is missing from S3 (or whatever blob storage vendor you're using).

In the second error you posted, there's also a MissingFormXML error being raised for the 3502d374-f25a-402d-b573-d51388680374 document. From what I can tell, this is raised when attachments are not found (in the object storage DB like S3). It doesn't seem related to the first issue though. A longer stacktrace for this might help more.

sirajhassan · November 28, 2023, 8:12am

Thank @smittieC for your kind response.

This is the longer stacktrace.

github.com

siraj-hassan/my-logs/blob/main/pillowtop-case-pillow-log.md


2023-11-21 18:26:07,303 ERROR [notify] Notify Exception: case-pillow Error in processing changes chunk: cc404ae1-366e-4d4f-9006-51a3a255b188
Traceback (most recent call last):
  File "/home/cchq/www/echis/releases/2023-11-21_11.15/corehq/blobs/s3db.py", line 175, in maybe_not_found
    yield
  File "/home/cchq/www/echis/releases/2023-11-21_11.15/corehq/blobs/s3db.py", line 99, in get
    resp = self._s3_bucket().Object(key).get()
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/boto3/resources/factory.py", line 580, in do_action
    response = action(self, *args, **kwargs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/boto3/resources/action.py", line 88, in __call__
    response = getattr(parent.meta.client, operation_name)(*args, **params)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/botocore/client.py", line 514, in _api_call
    return self._make_api_call(operation_name, kwargs)
  File "/home/cchq/www/echis/current/python_env/lib/python3.9/site-packages/botocore/client.py", line 938, in _make_api_call
    raise error_class(parsed_response, operation_name)
botocore.errorfactory.NoSuchKey: An error occurred (NoSuchKey) when calling the GetObject operation: The specified key does not exist.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):

This file has been truncated. show original

smittieC · December 4, 2023, 7:35am

@sirajhassan Apologies for the radio silence. My understanding is that data got lost, and the pillow is throwing an exception because of that. Do you have backups perhaps? Might be best to see if you can't restore the missing data from the backup.

sirajhassan · December 4, 2023, 8:29am

Hi @smittieC,

Yes, the pillow is comfortable with the backup database.
Is there any tool to export/import data submitted after the problem?

Thank you,

smittieC · December 5, 2023, 7:35am

@sirajhassan
Not that I am aware of no. Assuming that only minio data got lost, I'm wondering if you could not write some script to essentially sync the primary minio instance with the backup.

Looping in @Norman_Hooper as an FYI.

sirajhassan · December 5, 2023, 11:47am

@smittieC
The issue was persisting even though minio was restored to normal functioning after fsck. Now the error is not appearing and the case-pillow is green after we restored the backup PostgresSQL DB.

Thank you so much for your usual support.

smittieC · December 5, 2023, 12:40pm

@sirajhassan Glad to hear. Did you verify that the forms/documents that caused the errors are not causing them anymore?

sirajhassan · December 8, 2023, 2:33pm

Hi @smittieC,

MissingFormXml error is appearing in xform-pillow and UnknownUsersPillow log.
May be we have to wait till the green key of minio heal gets up? Right now it is 18%.

smittieC · December 12, 2023, 5:50am

@sirajhassan

May be we have to wait till the green key of minio heal gets up?

yeah, might be worth it to wait. Seemed like it worked last time.

sirajhassan · December 25, 2023, 8:55am

Hi Chris (@smittieC),

Even though we agreed to use the backup, we are imposed to lose some data submitted after the incident due to export/import difficulty.

Tried to find out the corrupted part of the database, it was 'pillow_retry_pillowerror' table in commcarehq database.

Unable to re-index the table to fix the issue. The error has gone after replacing its whole data with backup data (values of 'pillow_retry_pillowerror' table from backup database).
Now waiting to see the case-pillow is fully propagated and turned to green.

Will reach out to you.

Thank you,

sirajhassan · January 3, 2024, 2:02pm

Hi @smittieC,

Everything looks good except the following error when try to deploy the code even though --skip-record tag is used.

---------------- Pillow Errors Reset ----------------
4735182 pillow errors queued for retry

Thank you,

smittieC · January 5, 2024, 1:03pm

Hi @sirajhassan

That is just the amount of pillow errors that were reset (see this). I believe this will cause the pillows to retry any failures.