search

internetarchive / warcprox

WARC writing MITM HTTP/S proxy
378 stars 54 forks source link

Another exception when trying to close a WARC file #142

Closed vbanos closed 4 years ago

vbanos commented 4 years ago

Recently, we found and fixed a problem when closing a WARC file. https://github.com/internetarchive/warcprox/pull/140

After using the updated warcprox in production, we got another exception in the same method, right after that point.

ERROR:root:caught exception processing
b'https://abs.twimg.com/favicons/favicon.ico'
Traceback (most recent call last):
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/writerthread.py",
line 78, in _process_url
    records = self.writer_pool.write_records(recorded_url)
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/writer.py", line
227, in write_records
    return self._writer(recorded_url).write_records(recorded_url)
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/writer.py", line
139, in write_records
    offset = self.f.tell()
ValueError: I/O operation on closed file
ERROR:warcprox.writer.WarcWriter:could not unlock file
/1/liveweb/warcs/liveweb-20190923194044-wwwb-spn14.us.archive.org.warc.gz
(I/O operation on closed file)
CRITICAL:warcprox.writerthread.WarcWriterProcessor:WarcWriterProcessor(tid=6228)
will try to continue after unexpected error
Traceback (most recent call last):
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/__init__.py",
line 140, in _run
    self._get_process_put()
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/writerthread.py",
line 60, in _get_process_put
    self.writer_pool.maybe_idle_rollover()
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/writer.py", line
233, in maybe_idle_rollover
    w.maybe_idle_rollover()
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/writer.py", line
188, in maybe_idle_rollover
    self.close()
  File "/opt/spn2/lib/python3.5/site-packages/warcprox/writer.py", line
176, in close
    os.rename(self.path, finalpath)
FileNotFoundError: [Errno 2] No such file or directory:
'/1/liveweb/warcs/liveweb-20190923194044-wwwb-spn14.us.archive.org.warc.gz'
->
'/1/liveweb/warcs/liveweb-20190923194044-wwwb-spn14.us.archive.org.warc.gz'

We don't have a WARC file and our code tries to run os.rename on a file that doesn't exist. We add exception handling for that case as well.

I should have foreseen that when doing the previous fix :(

vbanos commented 4 years ago

@nlevitt The error log I posted also answers your question about what happened right before the error that triggered the WARC writer exception. When writing records, self.f.tell() raised ValueError: I/O operation on closed file.

nlevitt commented 4 years ago

Looks good to me.

The self.f.tell() exception is interesting, but needless to say, I wonder why the file was closed at that point...