Log filtering logic cannot handle logs from within nested exceptions

[mplough-kobold]

Steps to reproduce the problem.

Create sample input

1. Download the sample shapefile from https://docs.mapbox.com/help/glossary/shapefile/.
2. Use QGIS to edit the shapefile to have a date column. Add a couple of non-null dates.
3. In a hex editor, edit the stations.dbf file so that one of the dates has an invalid month, 13.
4. Create an archive of the invalid shapefiles called stations-bad-date.zip.

The result is attached: stations-bad-date.zip

Attempt to read the sample input:

1. Run the following code:

import fiona

with fiona.open("zip://stations-bad-date.zip", "r") as src:
    print(len([f for f in src]))

Expected behavior and actual behavior.

Expected behavior

A log message is emitted.

Date/time validation logic is enclosed in a try/except block, so the bad feature should be ignored with a log message emitted.

Fiona/fiona/ogrext.pyx

Lines 273 to 282 in 9dca27d

	try:
	if fieldtype is FionaDateType:
	props[key] = datetime.date(y, m, d).isoformat()
	elif fieldtype is FionaTimeType:
	props[key] = datetime.time(hh, mm, ss, ms, tzinfo).isoformat()
	else:
	props[key] = datetime.datetime(y, m, d, hh, mm, ss, ms, tzinfo).isoformat()
	except ValueError as err:
	log.exception(err)
	props[key] = None

Actual behavior

Instead, an uncaught exception occurs because the log filtering logic in logutils.py expects to handle strings and not objects of type Exception. An exception object ends up being passed through FieldSkipLogFilter.filter because there is a nested exception. This issue will occur any time logging occurs during handling of a nested exception.

Traceback (most recent call last):
  File "fiona/ogrext.pyx", line 271, in fiona.ogrext.FeatureBuilder.build
ValueError: month must be in 1..12

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "fiona_test.py", line 4, in <module>
    print(len([f for f in src]))
  File "fiona_test.py", line 4, in <listcomp>
    print(len([f for f in src]))
  File "fiona/ogrext.pyx", line 1515, in fiona.ogrext.Iterator.__next__
  File "fiona/ogrext.pyx", line 277, in fiona.ogrext.FeatureBuilder.build
  File "/Users/mplough/.pyenv/versions/3.8.5/lib/python3.8/logging/__init__.py", line 1469, in exception
    self.error(msg, *args, exc_info=exc_info, **kwargs)
  File "/Users/mplough/.pyenv/versions/3.8.5/lib/python3.8/logging/__init__.py", line 1463, in error
    self._log(ERROR, msg, args, **kwargs)
  File "/Users/mplough/.pyenv/versions/3.8.5/lib/python3.8/logging/__init__.py", line 1577, in _log
    self.handle(record)
  File "/Users/mplough/.pyenv/versions/3.8.5/lib/python3.8/logging/__init__.py", line 1586, in handle
    if (not self.disabled) and self.filter(record):
  File "/Users/mplough/.pyenv/versions/3.8.5/lib/python3.8/logging/__init__.py", line 807, in filter
    result = f.filter(record)
  File "/Users/mplough/.pyenv/versions/shapefile-test/lib/python3.8/site-packages/fiona/logutils.py", line 18, in filter
    if getattr(record, 'msg', "").startswith("Skipping field"):
AttributeError: 'ValueError' object has no attribute 'startswith'

Operating system

This issue occurs on Linux as well as on macOS; the problem is independent of operating system and has to do with the Fiona's log filtering logic.

Fiona and GDAL version and provenance

Fiona 1.8.20 from PyPI.
GDAL 3.3.2 from Homebrew.

[sgillies]

Thank you for the careful analysis @mplough-kobold ! This will be fixed in 1.8.21.