AmpelProject/Ampel-core

Potential race condition in DBLoggingHandler.flush

jvansanten opened this issue · 0 comments

During the recent ZTFBh rerun, 18 of 20 ampel-ztf-alertprocessors eventually failed with:

INFO:ampel.ztf.archive:Query complete after 5000 alerts, 9322 chunks remaining
<2019-02-23 01:04:16 log DBRejectedLogsSaver WARN>
  Overwriting rejected alerts logs
<2019-02-23 01:04:17 LoggingUtils ERROR>
  --------------------------------------------------
  Primary exception:
  Traceback (most recent call last):
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 286, in flush
      self.col.insert_many(dicts)
    File "/opt/conda/envs/ampel/lib/python3.6/site-packages/pymongo/collection.py", line 738, in insert_many
      raise TypeError("documents must be a non-empty list")
  TypeError: documents must be a non-empty list
  --------------------------------------------------
<2019-02-23 01:04:17 DBUpdateException ERROR>
  DB log flushing error, un-flushed (json) logs below.
  ****************************************************
  ####################################################
<2019-02-23 01:04:17 LoggingUtils ERROR>
  --------------------------------------------------
  Traceback (most recent call last):
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 286, in flush
      self.col.insert_many(dicts)
    File "/opt/conda/envs/ampel/lib/python3.6/site-packages/pymongo/collection.py", line 738, in insert_many
      raise TypeError("documents must be a non-empty list")
  TypeError: documents must be a non-empty list
  --------------------------------------------------
<2019-02-23 01:04:17 LoggingUtils ERROR>
  --------------------------------------------------
  Primary exception:
  Traceback (most recent call last):
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 128, in emit
      self.flush()
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 296, in flush
      raise e
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 286, in flush
      self.col.insert_many(dicts)
    File "/opt/conda/envs/ampel/lib/python3.6/site-packages/pymongo/collection.py", line 738, in insert_many
      raise TypeError("documents must be a non-empty list")
  TypeError: documents must be a non-empty list
  --------------------------------------------------
<2019-02-23 01:04:17 DBUpdateException ERROR>
  DB log flushing error, un-flushed (json) logs below.
  ****************************************************
  ####################################################
<2019-02-23 01:04:17 LoggingUtils ERROR>
  --------------------------------------------------
  Traceback (most recent call last):
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 128, in emit
      self.flush()
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 296, in flush
      raise e
    File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 286, in flush
      self.col.insert_many(dicts)
    File "/opt/conda/envs/ampel/lib/python3.6/site-packages/pymongo/collection.py", line 738, in insert_many
      raise TypeError("documents must be a non-empty list")
  TypeError: documents must be a non-empty list
  --------------------------------------------------
INFO:ampel-ztf-alertprocessor:(archive) 5000 alerts in 10.1s; 494.2/s
Traceback (most recent call last):
  File "/opt/conda/envs/ampel/bin/ampel-ztf-alertprocessor", line 11, in <module>
    load_entry_point('Ampel-ZTF', 'console_scripts', 'ampel-ztf-alertprocessor')()
  File "/Ampel/ampel-ztf/src/ampel/ztf/pipeline/t0/run.py", line 182, in run_alertprocessor
    alert_processed = processor.run(loader, full_console_logging=opts.verbose)
  File "/Ampel/ampel-core/src/ampel/pipeline/t0/AlertProcessor.py", line 458, in run
    db_logging_handler.handle(lr)
  File "/opt/conda/envs/ampel/lib/python3.6/logging/__init__.py", line 865, in handle
    self.emit(record)
  File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 174, in emit
    raise e from None
  File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 128, in emit
    self.flush()
  File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 296, in flush
    raise e
  File "/Ampel/ampel-core/src/ampel/pipeline/logging/DBLoggingHandler.py", line 286, in flush
    self.col.insert_many(dicts)
  File "/opt/conda/envs/ampel/lib/python3.6/site-packages/pymongo/collection.py", line 738, in insert_many
    raise TypeError("documents must be a non-empty list")
TypeError: documents must be a non-empty list
failed permanently with status 1

This could happen if, for example, flush() were called from another thread between the check for if not self.log_dicts and the actual insert_many() call. See also #69.