When TimeoutError occurred, StreamWriter close will be hold for a long time and failed with Connection timed out finally.
Closed this issue · 0 comments
DEBUG 2023-09-01 09:04:30,807 - iso15118.shared.security (892): Verifying digest for element with ID 'ID_MR'
DEBUG 2023-09-01 09:04:30,809 - iso15118.shared.security (905):
Received digest of reference with ID ID_MR: 28D17741A2B21FD963890E915F00F5687C67201A93809CE154901F9982A068C8
Calculated digest for reference: 28D17741A2B21FD963890E915F00F5687C67201A93809CE154901F9982A068C8
=> Match: True
DEBUG 2023-09-01 09:04:30,811 - iso15118.shared.security (918): Verifying signature value for SignedInfo element
INFO 2023-09-01 09:04:30,814 - iso15118.shared.exi_codec (245): Message to encode (ns=http://www.w3.org/2000/09/xmldsig#):
{"SignedInfo": {"CanonicalizationMethod": {"Algorithm": "http://www.w3.org/TR/canonical-exi/"}, "SignatureMethod": {"Algorithm": "http://www.w3.org/2001/04/xmldsig-more#ecdsa-sha256"}, "Reference": [{"Transforms": {"Transform": [{"Algorithm": "http://www.w3.org/TR/canonical-exi/"}]}, "DigestMethod": {"Algorithm": "http://www.w3.org/2001/04/xmlenc#sha256"}, "DigestValue": "KNF3QaKyH9ljiQ6RXwD1aHxnIBqTgJzhVJAfmYKgaMg=", "URI": "#ID_MR"}]}}
WARNING 2023-09-01 09:04:31,051 - iso15118.shared.security (985): Sub-CA and root CA certificates were not used to verify signatures along the certificate chain
DEBUG 2023-09-01 09:04:31,052 - iso15118.shared.security (990): Signature verified successfully
INFO 2023-09-01 09:04:31,057 - iso15118.shared.exi_codec (245): Message to encode (ns=urn:iso:15118:2:2013:MsgDef):
{"V2G_Message": {"Header": {"SessionID": "0949144431E2C1EC"}, "Body": {"MeteringReceiptRes": {"ResponseCode": "OK", "DC_EVSEStatus": {"NotificationMaxDelay": 0, "EVSENotification": "None", "EVSEIsolationStatus": "Valid", "EVSEStatusCode": "EVSE_Ready"}}}}}
INFO 2023-09-01 09:04:31,332 - iso15118.shared.comm_session (436): Sent MeteringReceiptRes
INFO 2023-09-01 09:04:31,333 - iso15118.secc.controller.simulator (650): iso15118 state: MeteringReceipt
INFO 2023-09-01 09:05:31,396 - iso15118.shared.comm_session (404): The data link will terminate in 2 seconds and the TCP connection will close in 5 seconds.
INFO 2023-09-01 09:05:31,397 - iso15118.shared.comm_session (408): Reason: TimeoutError occurred. Waited for 60.0 s after sending last message: [Header = [0x1, 0xfe, 0x8001, 18], Payload = 809802025245110c78b07b11000400001020)]
INFO 2023-09-01 09:05:33,400 - iso15118.shared.comm_session (415): terminated the data link
ERROR 2023-09-01 09:20:45,902 - iso15118.shared.utils (126): [Errno 110] Connection timed out
Traceback (most recent call last):
File "/usr/local/lib/python3.9/asyncio/streams.py", line 684, in read
await self._wait_for_data('read')
File "/usr/local/lib/python3.9/asyncio/streams.py", line 517, in _wait_for_data
await self._waiter
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
fut.result()
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/home/pi/projects/pyv2g/iso15118/shared/comm_session.py", line 458, in rcv_loop
message = await asyncio.wait_for(self.reader.read(7000), timeout)
File "/usr/local/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/home/pi/projects/pyv2g/iso15118/shared/utils.py", line 124, in wait_for_tasks
task.result()
File "/home/pi/projects/pyv2g/iso15118/shared/comm_session.py", line 490, in rcv_loop
await self.stop(reason=error_msg)
File "/home/pi/projects/pyv2g/iso15118/shared/comm_session.py", line 419, in stop
await self.writer.wait_closed()
File "/usr/local/lib/python3.9/asyncio/streams.py", line 359, in wait_closed
await self._protocol._get_close_waiter(self)
File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 856, in _read_ready__data_received
data = self._sock.recv(self.max_size)
TimeoutError: [Errno 110] Connection timed out
^CWARNING 2023-09-01 09:31:33,582 - iso15118.secc.transport.tcp_server (149): Closing TCP server
DEBUG 2023-09-01 09:31:33,589 - main (35): SECC program terminated manually