Repository: meltano/sdk (python)

Issue:
bug: mapper built on SDK errors with `AttributeError: 'str' object has no attribute 'tzinfo`
### Singer SDK Version

0.30.0

### Is this a regression?

- [ ] Yes

### Python Version

NA

### Bug scope

Mapping (stream maps, flattening, etc.)

### Operating System

macOS 12.6, Python 3.11

### Description

I scaffolded a new mapper project from the SDK using `cookiecutter https://github.com/meltano/sdk --directory="cookiecutter/mapper-template"`. I am now trying to test the default behavior (that is, not actually changing any data yet).

I have a few records in a CSV and am testing with `meltano run tap-csv test-decrypt target-jsonl` (where `test-decrypt` is a mapping using my mapper plugin)

I'm getting the following error:

```
$ meltano run tap-csv test-decrypt target-jsonl > out.txt
2023-08-08T16:34:01.331213Z [info     ] Environment 'test' is active
2023-08-08T16:34:04.147620Z [info     ] 2023-08-08 11:34:04,147 | INFO     | tap-csv              | Beginning full_table sync of 'records'... cmd_type=elb consumer=False name=tap-csv producer=True stdio=stderr string_id=tap-csv
2023-08-08T16:34:04.148384Z [info     ] 2023-08-08 11:34:04,147 | INFO     | tap-csv              | Tap has custom mapper. Using 1 provided map(s). cmd_type=elb consumer=False name=tap-csv producer=True stdio=stderr string_id=tap-csv
2023-08-08T16:34:04.150451Z [info     ] 2023-08-08 11:34:04,150 | INFO     | singer_sdk.metrics   | METRIC: {"type": "timer", "metric": "sync_duration", "value": 0.002245187759399414, "tags": {"stream": "records", "context": {}, "status": "succeeded"}} cmd_type=elb consumer=False name=tap-csv producer=True stdio=stderr string_id=tap-csv
2023-08-08T16:34:04.150825Z [info     ] 2023-08-08 11:34:04,150 | INFO     | singer_sdk.metrics   | METRIC: {"type": "counter", "metric": "record_count", "value": 4, "tags": {"stream": "records", "context": {}}} cmd_type=elb consumer=False name=tap-csv producer=True stdio=stderr string_id=tap-csv
2023-08-08T16:34:04.241283Z [info     ] Traceback (most recent call last): cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.241530Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/bin/mapper-my-test-mapper", line 8, in <module> cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.241804Z [info     ]     sys.exit(PawEltDecrypterMapper.cli()) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.241972Z [info     ]              ^^^^^^^^^^^^^^^^^^^^^^^^^^^ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.242135Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/click/core.py", line 1157, in __call__ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.242291Z [info     ]     return self.main(*args, **kwargs) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.242466Z [info     ]            ^^^^^^^^^^^^^^^^^^^^^^^^^^ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.242797Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/click/core.py", line 1078, in main cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.243029Z [info     ]     rv = self.invoke(ctx)      cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.243185Z [info     ]          ^^^^^^^^^^^^^^^^      cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.243332Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/click/core.py", line 1434, in invoke cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.243480Z [info     ]     return ctx.invoke(self.callback, **ctx.params) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.243641Z [info     ]            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.243801Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/click/core.py", line 783, in invoke cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.243967Z [info     ]     return __callback(*args, **kwargs) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.244111Z [info     ]            ^^^^^^^^^^^^^^^^^^^^^^^^^^^ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.244253Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/singer_sdk/mapper_base.py", line 134, in invoke cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.244399Z [info     ]     mapper.listen(file_input)  cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.244536Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/singer_sdk/io_base.py", line 34, in listen cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.244782Z [info     ]     self._process_lines(file_input) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.244974Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/singer_sdk/io_base.py", line 93, in _process_lines cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.245129Z [info     ]     self._process_record_message(line_dict) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.245277Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/singer_sdk/mapper_base.py", line 40, in _process_record_message cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.245421Z [info     ]     self._write_messages(self.map_record_message(message_dict)) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.245561Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/singer_sdk/mapper_base.py", line 33, in _write_messages cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.245701Z [info     ]     for message in messages:   cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.245843Z [info     ]   File "/Users/matt/dev/my-test-mapper/my_test_mapper/mapper.py", line 73, in map_record_message cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.245983Z [info     ]     yield singer.RecordMessage.from_dict(message_dict) cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.246124Z [info     ]           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.246261Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/singer_sdk/_singerlib/messages.py", line 68, in from_dict cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.246401Z [info     ]     return cls(**data)         cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.246538Z [info     ]            ^^^^^^^^^^^         cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.246695Z [info     ]   File "<string>", line 7, in __init__ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.246834Z [info     ]   File "/Users/matt/dev/my-test-mapper/.meltano/mappers/my-test-mapper/venv/lib/python3.11/site-packages/singer_sdk/_singerlib/messages.py", line 114, in __post_init__ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.246973Z [info     ]     if self.time_extracted and not self.time_extracted.tzinfo: cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.247109Z [info     ]                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^ cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.247246Z [info     ] AttributeError: 'str' object has no attribute 'tzinfo' cmd_type=elb consumer=True name=my-test-mapper producer=True stdio=stderr string_id=my-test-mapper
2023-08-08T16:34:04.337947Z [info     ] Incremental state has been updated at 2023-08-08 16:34:04.337835.
2023-08-08T16:34:04.344475Z [error    ] Mappers failed
2023-08-08T16:34:04.344918Z [error    ] Block run completed.           block_type=ExtractLoadBlocks err=RunnerError('Mappers failed') exit_codes=[{'my-test-mapper': 1}] set_number=0 success=False
Need help fixing this problem? Visit http://melta.no/ for troubleshooting steps, or to
join our friendly Slack community.

Run invocation could not be completed as block failed: Mappers failed
```

I believe this means that the `self.time_extracted` member is a string, when it's not expected to be.

### Code

_No response_

Pull request:
fix: Parse record `time_extracted` into `datetime.datetime` instance
Closes #1902 

<!-- readthedocs-preview meltano-sdk start -->
----
:books: Documentation preview :books:: https://meltano-sdk--2006.org.readthedocs.build/en/2006/

<!-- readthedocs-preview meltano-sdk end -->

Patch:
diff --git a/singer_sdk/_singerlib/messages.py b/singer_sdk/_singerlib/messages.py
index 7fc17e57..02c0f30f 100644
--- a/singer_sdk/_singerlib/messages.py
+++ b/singer_sdk/_singerlib/messages.py
@@ -6,9 +6,10 @@ import enum
 import sys
 import typing as t
 from dataclasses import asdict, dataclass, field
+from datetime import timezone
 
-import pytz
 import simplejson as json
+from dateutil.parser import parse
 
 if t.TYPE_CHECKING:
     from datetime import datetime
@@ -84,6 +85,27 @@ class RecordMessage(Message):
     time_extracted: datetime | None = None
     """The time the record was extracted."""
 
+    @classmethod
+    def from_dict(cls: type[RecordMessage], data: dict[str, t.Any]) -> RecordMessage:
+        """Create a record message from a dictionary.
+
+        This overrides the default conversion logic, since it uses unnecessary
+        deep copying and is very slow.
+
+        Args:
+            data: The dictionary to create the message from.
+
+        Returns:
+            The created message.
+        """
+        time_extracted = data.get("time_extracted")
+        return cls(
+            stream=data["stream"],
+            record=data["record"],
+            version=data.get("version"),
+            time_extracted=parse(time_extracted) if time_extracted else None,
+        )
+
     def to_dict(self) -> dict[str, t.Any]:
         """Return a dictionary representation of the message.
 
@@ -119,7 +141,7 @@ class RecordMessage(Message):
             raise ValueError(msg)
 
         if self.time_extracted:
-            self.time_extracted = self.time_extracted.astimezone(pytz.utc)
+            self.time_extracted = self.time_extracted.astimezone(timezone.utc)
 
 
 @dataclass


Test patch:
diff --git a/tests/_singerlib/test_messages.py b/tests/_singerlib/test_messages.py
index 47a36aca..b4a33db4 100644
--- a/tests/_singerlib/test_messages.py
+++ b/tests/_singerlib/test_messages.py
@@ -1,15 +1,17 @@
 from __future__ import annotations
 
+import datetime
 import io
 from contextlib import redirect_stdout
-from datetime import datetime
 
 import pytest
-from pytz import UTC, timezone
+from pytz import timezone
 
 import singer_sdk._singerlib as singer
 from singer_sdk._singerlib.messages import format_message
 
+UTC = datetime.timezone.utc
+
 
 def test_exclude_null_dict():
     pairs = [("a", 1), ("b", None), ("c", 3)]
@@ -55,19 +57,33 @@ def test_record_message():
     assert singer.RecordMessage.from_dict(record.to_dict()) == record
 
 
+def test_record_message_parse_time_extracted():
+    message_dic = {
+        "type": "RECORD",
+        "stream": "test",
+        "record": {"id": 1, "name": "test"},
+        "time_extracted": "2021-01-01T00:00:00Z",
+    }
+    record = singer.RecordMessage.from_dict(message_dic)
+    assert record.type == "RECORD"
+    assert record.stream == "test"
+    assert record.record == {"id": 1, "name": "test"}
+    assert record.time_extracted == datetime.datetime(2021, 1, 1, 0, 0, 0, tzinfo=UTC)
+
+
 def test_record_message_naive_time_extracted():
     """Check that record message' time_extracted must be timezone-aware."""
     with pytest.raises(ValueError, match="must be either None or an aware datetime"):
         singer.RecordMessage(
             stream="test",
             record={"id": 1, "name": "test"},
-            time_extracted=datetime(2021, 1, 1),  # noqa: DTZ001
+            time_extracted=datetime.datetime(2021, 1, 1),  # noqa: DTZ001
         )
 
 
 def test_record_message_time_extracted_to_utc():
     """Check that record message's time_extracted is converted to UTC."""
-    naive = datetime(2021, 1, 1, 12)  # noqa: DTZ001
+    naive = datetime.datetime(2021, 1, 1, 12)  # noqa: DTZ001
     nairobi = timezone("Africa/Nairobi")
 
     record = singer.RecordMessage(
@@ -75,7 +91,7 @@ def test_record_message_time_extracted_to_utc():
         record={"id": 1, "name": "test"},
         time_extracted=nairobi.localize(naive),
     )
-    assert record.time_extracted == datetime(2021, 1, 1, 9, tzinfo=UTC)
+    assert record.time_extracted == datetime.datetime(2021, 1, 1, 9, tzinfo=UTC)
 
 
 def test_schema_message():