project-koku / masu

This is a READ ONLY repo. See https://github.com/project-koku/koku for current masu implementation
GNU Affero General Public License v3.0
5 stars 6 forks source link

masu-listener becomes unusable when line item processing fails. #462

Closed dccurtis closed 5 years ago

dccurtis commented 5 years ago

The following exception was seen in hccm-qa. While it's not clear why this database schema issue occurred the larger problem was that the listener appeared to be blocked awaiting on the process_report thread to return. The listener was completely locked and unable to service any subsequent processing events.

The problem is that there is a try/catch block missing around the run_in_executor call

[2019-06-11 13:20:00,013] INFO in ocp_report_processor: File <_io.TextIOWrapper name='/var/tmp/masu/acct477931/ocp/test3-ocp-delta/20190601-20190701_6e07e100-71cc-42f5-a635-5f8844aae091_openshift_usage_report.0.csv' mode='r' encoding='UTF-8'> opened for processing
[2019-06-11 13:20:05,806] INFO in ocp_report_processor: Saving report rows 0 to 253 for 20190601-20190701_6e07e100-71cc-42f5-a635-5f8844aae091_openshift_usage_report.0.csv
[2019-06-11 13:20:05,807] INFO in ocp_report_processor: Completed report processing for file: /var/tmp/masu/acct477931/ocp/test3-ocp-delta/20190601-20190701_6e07e100-71cc-42f5-a635-5f8844aae091_openshift_usage_report.0.csv and schema: acct477931
[2019-06-11 13:20:09,307] INFO in ocp_report_processor: Cleaning up temporary report files for /var/tmp/masu/acct477931/ocp/test3-ocp-delta
[2019-06-11 13:20:15,609] INFO in ocp_report_processor: Removing /var/tmp/masu/acct477931/ocp/test3-ocp-delta/20190601-20190701_5c979ea3-67de-411a-9a2c-89f735ead5c9_openshift_usage_report.1.csv, completed processing on date 2019-06-11 13:19:40.353455+00:00
[2019-06-11 13:20:15,609] INFO in ocp_report_processor: Removing /var/tmp/masu/acct477931/ocp/test3-ocp-delta/20190601-20190701_5c979ea3-67de-411a-9a2c-89f735ead5c9_openshift_usage_report.0.csv, completed processing on date 2019-06-11 13:19:36.360707+00:00
[2019-06-11 13:20:24,410] INFO in ocp_report_processor: Initialized report processor for file: /var/tmp/masu/acct477931/ocp/test3-ocp-delta/20190601-20190701_6e07e100-71cc-42f5-a635-5f8844aae091_openshift_usage_report.1.csv and schema: acct477931
[2019-06-11 13:20:26,913] INFO in ocp_report_processor: File <_io.TextIOWrapper name='/var/tmp/masu/acct477931/ocp/test3-ocp-delta/20190601-20190701_6e07e100-71cc-42f5-a635-5f8844aae091_openshift_usage_report.1.csv' mode='r' encoding='UTF-8'> opened for processing
[2019-06-11 13:20:32,018] INFO in ocp_report_processor: Saving report rows 0 to 253 for 20190601-20190701_6e07e100-71cc-42f5-a635-5f8844aae091_openshift_usage_report.1.csv
[2019-06-11 13:20:32,019] INFO in ocp_report_processor: Completed report processing for file: /var/tmp/masu/acct477931/ocp/test3-ocp-delta/20190601-20190701_6e07e100-71cc-42f5-a635-5f8844aae091_openshift_usage_report.1.csv and schema: acct477931
Task exception was never retrieved
future: <Task finished coro=<process_messages() done, defined at /opt/app-root/src/masu/external/kafka_msg_handler.py:290> exception=AttributeError("'NoneType' object has no attribute 'setup_complete'",)>
Traceback (most recent call last):
  File "/opt/app-root/src/masu/external/kafka_msg_handler.py", line 309, in process_messages
    await EVENT_LOOP.run_in_executor(pool, process_report, report_meta)
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/opt/app-root/src/masu/external/kafka_msg_handler.py", line 283, in process_report
    reports_to_summarize = get_report_files(**account)
  File "/opt/app-root/lib/python3.6/site-packages/celery/local.py", line 191, in __call__
    return self._get_current_object()(*a, **kw)
  File "/opt/app-root/src/masu/celery/__init__.py", line 91, in __call__
    return self.run(*args, **kwargs)
  File "/opt/app-root/src/masu/processor/tasks.py", line 108, in get_report_files
    report_dict)
  File "/opt/app-root/src/masu/processor/_tasks/process.py", line 94, in _process_report_file
    provider_accessor.setup_complete()
  File "/opt/app-root/src/masu/database/provider_db_accessor.py", line 161, in setup_complete
    obj.setup_complete = True
AttributeError: 'NoneType' object has no attribute 'setup_complete'
lcouzens commented 5 years ago

Not easily reproducible so we will close this and re-raise if its ever seen again.