ASCWriter speed improvement (#1856)

* ASCWriter speed improvement

Changed how the message data is converted to string. This results in and 100% speed improvement.

On my PC, before the change, logging 10000 messages was taking ~16 seconds and this change drop it to ~8 seconds. With this change, the ASCWriter is still one of the slowest writer we have in Python-can.

* Update asc.py

* Update logformats_test.py

* Create single_frame.asc

* Update logformats_test.py

* Update test/logformats_test.py

Co-authored-by: Felix Divo <4403130+felixdivo@users.noreply.github.com>

---------

Co-authored-by: Felix Divo <4403130+felixdivo@users.noreply.github.com>

Author: pierreluctg

can/io/asc.py

@@ -9,7 +9,7 @@
 import logging
 import re
 from datetime import datetime
-from typing import Any, Dict, Final, Generator, List, Optional, TextIO, Union
+from typing import Any, Dict, Final, Generator, Optional, TextIO, Union
 
 from ..message import Message
 from ..typechecking import StringPathLike
@@ -439,10 +439,10 @@ def on_message_received(self, msg: Message) -> None:
             return
         if msg.is_remote_frame:
             dtype = f"r {msg.dlc:x}"  # New after v8.5
-            data: List[str] = []
+            data: str = ""
         else:
             dtype = f"d {msg.dlc:x}"
-            data = [f"{byte:02X}" for byte in msg.data]
+            data = msg.data.hex(" ").upper()
         arb_id = f"{msg.arbitration_id:X}"
         if msg.is_extended_id:
             arb_id += "x"
@@ -462,7 +462,7 @@ def on_message_received(self, msg: Message) -> None:
                 esi=1 if msg.error_state_indicator else 0,
                 dlc=len2dlc(msg.dlc),
                 data_length=len(msg.data),
-                data=" ".join(data),
+                data=data,
                 message_duration=0,
                 message_length=0,
                 flags=flags,
@@ -478,6 +478,6 @@ def on_message_received(self, msg: Message) -> None:
                 id=arb_id,
                 dir="Rx" if msg.is_rx else "Tx",
                 dtype=dtype,
-                data=" ".join(data),
+                data=data,
             )
         self.log_event(serialized, msg.timestamp)

test/data/single_frame.asc

@@ -0,0 +1,7 @@
+date Sat Sep 30 15:06:13.191 2017
+base hex  timestamps absolute
+internal events logged
+Begin Triggerblock Sat Sep 30 15:06:13.191 2017
+ 0.000000 Start of measurement
+ 0.000000 1  123x            Rx   d 40 00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F
+End TriggerBlock

test/logformats_test.py

@@ -651,6 +651,33 @@ def test_write_millisecond_handling(self):
 
         self.assertEqual(expected_file.read_text(), actual_file.read_text())
 
+    def test_write(self):
+        now = datetime(
+            year=2017, month=9, day=30, hour=15, minute=6, second=13, microsecond=191456
+        )
+
+        # We temporarily set the locale to C to ensure test reproducibility
+        with override_locale(category=locale.LC_TIME, locale_str="C"):
+            # We mock datetime.now during ASCWriter __init__ for reproducibility
+            # Unfortunately, now() is a readonly attribute, so we mock datetime
+            with patch("can.io.asc.datetime") as mock_datetime:
+                mock_datetime.now.return_value = now
+                writer = can.ASCWriter(self.test_file_name)
+
+            msg = can.Message(
+                timestamp=now.timestamp(),
+                arbitration_id=0x123,
+                data=range(64),
+            )
+
+            with writer:
+                writer.on_message_received(msg)
+
+        actual_file = Path(self.test_file_name)
+        expected_file = self._get_logfile_location("single_frame.asc")
+
+        self.assertEqual(expected_file.read_text(), actual_file.read_text())
+
 
 class TestBlfFileFormat(ReaderWriterTest):
     """Tests can.BLFWriter and can.BLFReader.