Running Josev/ISO15118 local with ISO15118-20 dc config JSON file on Raspberry Pi: EVCC terminates data link after Timeouts_EVCC_ONGOING_TIMEOUT s

Question

Running Josev/ISO15118 local with ISO15118-20 dc config JSON file on Raspberry Pi: EVCC terminates data link after Timeouts_EVCC_ONGOING_TIMEOUT s

Chengta-code opened this issue 5 months ago · 0 comments

I'm running Josev/ISO15118 locally on a Raspberry Pi 3 Model B with Raspberry Pi OS. However, the EVCC side terminates the data link during the Authorization STATE after waiting for Timeouts_EVCC_ONGOING_TIMEOUT seconds, causing the process to terminate. Below are the outputs from running make run-secc and make run-evcc. Despite adjusting the timeouts and increasing sdp_retry_cycles, the issue persists for ISO15118-20. This configuration works fine for ISO15118-2.

SECC does receive the AuthorizationReq msg(2283bytes), but it does not have a response "AuthorizationRes" to EVCC thus causing a timeout error. The reason may be on the EXICodec.jar since the message size is big therefore its response time is too long. (I recompiled the Linux kernel to increase the MTU size to 9000 to solve the EOF error caused by having the truncated message with an MTU limit of 1500.) (It is related to open issue #320) @shalinnijel2

I would greatly appreciate any help.

SECC SIDE***********************
(myenv) pi@raspberrypi:~/Downloads/iso15118-master $ make run-secc
poetry run python iso15118/secc/main.py
DEBUG 2024-07-12 02:43:48,680 - asyncio (54): Using selector: EpollSelector
INFO 2024-07-12 02:43:48,707 - iso15118.secc.secc_settings (112): SECC settings:
INFO 2024-07-12 02:43:48,708 - iso15118.secc.secc_settings (114): NETWORK_INTERFACE : eth0
INFO 2024-07-12 02:43:48,708 - iso15118.secc.secc_settings (114): LOG_LEVEL : DEBUG
INFO 2024-07-12 02:43:48,708 - iso15118.secc.secc_settings (114): SECC_ENFORCE_TLS : False
INFO 2024-07-12 02:43:48,709 - iso15118.secc.secc_settings (114): FREE_CHARGING_SERVICE : False
INFO 2024-07-12 02:43:48,709 - iso15118.secc.secc_settings (114): FREE_CERT_INSTALL_SERVICE : True
INFO 2024-07-12 02:43:48,710 - iso15118.secc.secc_settings (114): USE_CPO_BACKEND : False
INFO 2024-07-12 02:43:48,710 - iso15118.secc.secc_settings (114): ALLOW_CERT_INSTALL_SERVICE : True
INFO 2024-07-12 02:43:48,710 - iso15118.secc.secc_settings (114): PROTOCOLS : ['DIN_SPEC_70121', 'ISO_15118_2', 'ISO_15118_20_AC', 'ISO_15118_20_DC']
INFO 2024-07-12 02:43:48,711 - iso15118.secc.secc_settings (114): AUTH_MODES : ['EIM', 'PNC']
INFO 2024-07-12 02:43:48,711 - iso15118.secc.secc_settings (114): STANDBY_ALLOWED : False
INFO 2024-07-12 02:43:48,711 - iso15118.secc.secc_settings (114): PKI_PATH : /home/disby/Downloads/iso15118-master/iso15118/shared/pki/
INFO 2024-07-12 02:43:48,712 - iso15118.secc.secc_settings (114): MESSAGE_LOG_JSON : True
INFO 2024-07-12 02:43:48,712 - iso15118.secc.secc_settings (114): MESSAGE_LOG_EXI : False
INFO 2024-07-12 02:43:48,712 - iso15118.secc.secc_settings (114): ENABLE_TLS_1_3 : False
DEBUG 2024-07-12 02:43:48,713 - iso15118.secc.controller.simulator (262): New Status: ServiceStatus.STARTING
INFO 2024-07-12 02:43:56,973 - iso15118.shared.exi_codec (177): EXI Codec version: 1.55
INFO 2024-07-12 02:43:56,974 - iso15118.secc (31): Starting 15118 version: 0.28.3
INFO 2024-07-12 02:43:56,975 - iso15118.secc.comm_session_handler (235): Communication session handler started
INFO 2024-07-12 02:43:56,977 - iso15118.secc.transport.udp_server (137): UDP server socket ready
INFO 2024-07-12 02:43:56,978 - iso15118.secc.transport.udp_server (123): UDP server started at address FF02::1%eth0 and port 15118
DEBUG 2024-07-12 02:43:56,990 - iso15118.secc.controller.simulator (262): New Status: ServiceStatus.READY
DEBUG 2024-07-12 02:44:20,142 - iso15118.secc.transport.udp_server (158): Message received from ('fe80::ba27:ebff:fe03:ff88', 55407, 0, 2): 01fe9000000000021000
INFO 2024-07-12 02:44:20,144 - iso15118.secc.comm_session_handler (437): SDPRequest received: [Security: NO_TLS, Protocol: TCP]
INFO 2024-07-12 02:44:20,154 - iso15118.secc.transport.tcp_server (134): TCP server started at address fe80::ba27:ebff:fe98:a2bb%eth0 and port 56947
INFO 2024-07-12 02:44:20,164 - iso15118.secc.comm_session_handler (464): Sending SDPResponse: [ IP address: fe80::ba27:ebff:fe98:a2bb, Port: 56947 , Security: NO_TLS , Transport: TCP ]
Sending data to address: ('fe80::ba27:ebff:fe03:ff88', 55407, 0, 2)
INFO 2024-07-12 02:44:20,186 - iso15118.secc.transport.udp_server (201): UDP server has been paused.
INFO 2024-07-12 02:44:20,187 - iso15118.secc.comm_session_handler (284): TCP client connected, client address is ('fe80::ba27:ebff:fe03:ff88', 58634, 0, 2).
INFO 2024-07-12 02:44:20,247 - iso15118.shared.comm_session (344): Starting a new communication session
INFO 2024-07-12 02:44:20,248 - iso15118.shared.states (139): Entered state SupportedAppProtocol
DEBUG 2024-07-12 02:44:20,248 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 02:44:21,193 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.SAP): {"supportedAppProtocolReq":{"AppProtocol":[{"ProtocolNamespace":"urn:iso:std:iso:15118:-20:DC","VersionNumberMajor":1,"VersionNumberMinor":0,"SchemaID":1,"Priority":1}]}}
INFO 2024-07-12 02:44:21,194 - iso15118.shared.comm_session (235): supportedAppProtocolReq received
INFO 2024-07-12 02:44:21,197 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.SAP): {"supportedAppProtocolRes": {"ResponseCode": "OK_SuccessfulNegotiation", "SchemaID": 1}}
INFO 2024-07-12 02:44:21,393 - iso15118.secc.states.sap_states (147): Chosen protocol: ISO_15118_20_DC
INFO 2024-07-12 02:44:21,394 - iso15118.shared.comm_session (431): Sent supportedAppProtocolRes
INFO 2024-07-12 02:44:21,394 - iso15118.secc.controller.simulator (762): iso15118 state: SupportedAppProtocol
INFO 2024-07-12 02:44:21,395 - iso15118.shared.states (139): Entered state SessionSetup
DEBUG 2024-07-12 02:44:21,396 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 02:44:25,822 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.ISO_V20_COMMON_MSG): {"SessionSetupReq":{"Header":{"SessionID":"0000000000000000","TimeStamp":1720748662},"EVCCID":"WMIV1234567890ABCDEX"}}
INFO 2024-07-12 02:44:25,824 - iso15118.shared.comm_session (235): SessionSetupReq received
WARNING 2024-07-12 02:44:25,825 - iso15118.secc.states.iso15118_20_states (159): EVCC's session ID 0000000000000000 does not match . New session ID 79D447334105C288 assigned
INFO 2024-07-12 02:44:25,828 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"SessionSetupRes": {"Header": {"SessionID": "79D447334105C288", "TimeStamp": 1720748665}, "ResponseCode": "OK_NewSessionEstablished", "EVSEID": "UK123E1234"}}
INFO 2024-07-12 02:44:26,707 - iso15118.shared.comm_session (431): Sent SessionSetupRes
INFO 2024-07-12 02:44:26,708 - iso15118.secc.controller.simulator (762): iso15118 state: SessionSetup
INFO 2024-07-12 02:44:26,709 - iso15118.shared.states (139): Entered state AuthorizationSetup
DEBUG 2024-07-12 02:44:26,709 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 02:44:30,939 - iso15118.shared.comm_session (395): The data link will SessionStopAction.TERMINATE in 2 seconds and the TCP connection will close in 5 seconds.
INFO 2024-07-12 02:44:30,940 - iso15118.shared.comm_session (399): Reason: TCP peer closed connection
INFO 2024-07-12 02:44:32,942 - iso15118.secc.controller.simulator (1093): Session ended in AuthorizationSetup (TCP peer closed connection).
INFO 2024-07-12 02:44:32,943 - iso15118.shared.comm_session (410): SessionStopAction.TERMINATEd the data link
INFO 2024-07-12 02:44:35,946 - iso15118.shared.comm_session (417): TCP connection closed to peer with address ('fe80::ba27:ebff:fe03:ff88', 58634, 0, 2)
WARNING 2024-07-12 02:44:35,948 - iso15118.secc.transport.tcp_server (149): Closing TCP server
INFO 2024-07-12 02:44:35,949 - iso15118.secc.transport.udp_server (209): UDP server has been resumed.
DEBUG 2024-07-12 02:44:36,021 - iso15118.secc.transport.udp_server (158): Message received from ('fe80::ba27:ebff:fe03:ff88', 55407, 0, 2): 01fe9000000000021000
INFO 2024-07-12 02:44:36,023 - iso15118.secc.comm_session_handler (437): SDPRequest received: [Security: NO_TLS, Protocol: TCP]
INFO 2024-07-12 02:44:36,029 - iso15118.secc.transport.tcp_server (134): TCP server started at address fe80::ba27:ebff:fe98:a2bb%eth0 and port 56947
INFO 2024-07-12 02:44:36,038 - iso15118.secc.comm_session_handler (464): Sending SDPResponse: [ IP address: fe80::ba27:ebff:fe98:a2bb, Port: 56947 , Security: NO_TLS , Transport: TCP ]
Sending data to address: ('fe80::ba27:ebff:fe03:ff88', 55407, 0, 2)
INFO 2024-07-12 02:44:36,056 - iso15118.secc.transport.udp_server (201): UDP server has been paused.
INFO 2024-07-12 02:44:36,057 - iso15118.secc.comm_session_handler (284): TCP client connected, client address is ('fe80::ba27:ebff:fe03:ff88', 54044, 0, 2).
INFO 2024-07-12 02:44:36,058 - iso15118.shared.comm_session (344): Starting a new communication session
INFO 2024-07-12 02:44:36,058 - iso15118.shared.states (139): Entered state SupportedAppProtocol
DEBUG 2024-07-12 02:44:36,059 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 02:44:36,118 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.SAP): {"supportedAppProtocolReq":{"AppProtocol":[{"ProtocolNamespace":"urn:iso:std:iso:15118:-20:DC","VersionNumberMajor":1,"VersionNumberMinor":0,"SchemaID":1,"Priority":1}]}}
INFO 2024-07-12 02:44:36,119 - iso15118.shared.comm_session (235): supportedAppProtocolReq received
INFO 2024-07-12 02:44:36,120 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.SAP): {"supportedAppProtocolRes": {"ResponseCode": "OK_SuccessfulNegotiation", "SchemaID": 1}}
INFO 2024-07-12 02:44:36,133 - iso15118.secc.states.sap_states (147): Chosen protocol: ISO_15118_20_DC
INFO 2024-07-12 02:44:36,134 - iso15118.shared.comm_session (431): Sent supportedAppProtocolRes
INFO 2024-07-12 02:44:36,134 - iso15118.secc.controller.simulator (762): iso15118 state: SupportedAppProtocol
INFO 2024-07-12 02:44:36,134 - iso15118.shared.states (139): Entered state SessionSetup
DEBUG 2024-07-12 02:44:36,135 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 02:44:37,725 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.ISO_V20_COMMON_MSG): {"SessionSetupReq":{"Header":{"SessionID":"0000000000000000","TimeStamp":1720748676},"EVCCID":"WMIV1234567890ABCDEX"}}
INFO 2024-07-12 02:44:37,727 - iso15118.shared.comm_session (235): SessionSetupReq received
WARNING 2024-07-12 02:44:37,729 - iso15118.secc.states.iso15118_20_states (159): EVCC's session ID 0000000000000000 does not match . New session ID 00C0AD61A696C9E6 assigned
INFO 2024-07-12 02:44:37,731 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"SessionSetupRes": {"Header": {"SessionID": "00C0AD61A696C9E6", "TimeStamp": 1720748677}, "ResponseCode": "OK_NewSessionEstablished", "EVSEID": "UK123E1234"}}
INFO 2024-07-12 02:44:38,375 - iso15118.shared.comm_session (431): Sent SessionSetupRes
INFO 2024-07-12 02:44:38,377 - iso15118.secc.controller.simulator (762): iso15118 state: SessionSetup
INFO 2024-07-12 02:44:38,378 - iso15118.shared.states (139): Entered state AuthorizationSetup
DEBUG 2024-07-12 02:44:38,379 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 02:44:40,302 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.ISO_V20_COMMON_MSG): {"AuthorizationSetupReq":{"Header":{"SessionID":"00C0AD61A696C9E6","TimeStamp":1720748679}}}
INFO 2024-07-12 02:44:40,303 - iso15118.shared.comm_session (235): AuthorizationSetupReq received
INFO 2024-07-12 02:44:40,305 - iso15118.secc.states.iso15118_20_states (223): Processing message in AuthorizationSetup state
INFO 2024-07-12 02:44:40,309 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"AuthorizationSetupRes": {"Header": {"SessionID": "00C0AD61A696C9E6", "TimeStamp": 1720748680}, "ResponseCode": "OK", "AuthorizationServices": ["PnC", "EIM"], "CertificateInstallationService": true, "PnC_ASResAuthorizationMode": {"GenChallenge": "gQmoAjrjQw/N1J0d52pKrg=="}}}
INFO 2024-07-12 02:44:41,013 - iso15118.shared.comm_session (431): Sent AuthorizationSetupRes
INFO 2024-07-12 02:44:41,015 - iso15118.secc.controller.simulator (762): iso15118 state: AuthorizationSetup
INFO 2024-07-12 02:44:41,015 - iso15118.shared.states (139): Entered state Authorization
DEBUG 2024-07-12 02:44:41,016 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 02:45:41,065 - iso15118.shared.comm_session (395): The data link will SessionStopAction.TERMINATE in 2 seconds and the TCP connection will close in 5 seconds.
INFO 2024-07-12 02:45:41,066 - iso15118.shared.comm_session (399): Reason: TimeoutError occurred. Waited for Timeouts.V2G_EVCC_ONGOING_TIMEOUT s after sending last message: [Header = [0x1, 0xfe, 0x8002, 38], Payload = 800c04006056b0d34b64f308895c2b4062002012084084d4011d71a187e6ea4e8ef3b5255710)]
INFO 2024-07-12 02:45:43,068 - iso15118.secc.controller.simulator (1093): Session ended in Authorization (TimeoutError occurred. Waited for Timeouts.V2G_EVCC_ONGOING_TIMEOUT s after sending last message: [Header = [0x1, 0xfe, 0x8002, 38], Payload = 800c04006056b0d34b64f308895c2b4062002012084084d4011d71a187e6ea4e8ef3b5255710)]).
INFO 2024-07-12 02:45:43,069 - iso15118.shared.comm_session (410): SessionStopAction.TERMINATEd the data link
INFO 2024-07-12 02:45:46,074 - iso15118.shared.comm_session (417): TCP connection closed to peer with address ('fe80::ba27:ebff:fe03:ff88', 54044, 0, 2)
WARNING 2024-07-12 02:45:46,075 - iso15118.secc.transport.tcp_server (149): Closing TCP server
INFO 2024-07-12 02:45:46,076 - iso15118.secc.transport.udp_server (209): UDP server has been resumed.

******************************* EVCC SIDE ***************************************************
poetry run python iso15118/evcc/main.py
DEBUG 2024-07-12 09:44:09,078 - asyncio (54): Using selector: EpollSelector
INFO 2024-07-12 09:44:09,097 - iso15118.evcc.evcc_settings (46): EVCC environment settings:
INFO 2024-07-12 09:44:09,097 - iso15118.evcc.evcc_settings (48): PKI_PATH : /home/disby/Downloads/iso15118-master/iso15118/shared/pki/
INFO 2024-07-12 09:44:09,098 - iso15118.evcc.evcc_settings (48): MESSAGE_LOG_JSON : True
INFO 2024-07-12 09:44:09,098 - iso15118.evcc.evcc_settings (48): MESSAGE_LOG_EXI : False
INFO 2024-07-12 09:44:09,098 - iso15118.evcc.evcc_settings (48): ENABLE_TLS_1_3 : False
INFO 2024-07-12 09:44:09,106 - iso15118.evcc.evcc_settings (50): NETWORK_INTERFACE : eth0
INFO 2024-07-12 09:44:09,106 - iso15118.evcc.evcc_settings (50): LOG_LEVEL : DEBUG
INFO 2024-07-12 09:44:09,106 - iso15118.evcc.evcc_settings (50): EVCC_CONFIG_PATH : iso15118/shared/examples/evcc/iso15118_20/evcc_config_dc.json
INFO 2024-07-12 09:44:09,155 - iso15118.evcc.evcc_config (118): EVCC Settings
INFO 2024-07-12 09:44:09,157 - iso15118.evcc.evcc_config (121): supported_energy_services : [<ServiceV20.DC: 2>]
INFO 2024-07-12 09:44:09,157 - iso15118.evcc.evcc_config (121): is_cert_install_needed : False
INFO 2024-07-12 09:44:09,157 - iso15118.evcc.evcc_config (121): use_tls : False
INFO 2024-07-12 09:44:09,157 - iso15118.evcc.evcc_config (121): sdp_retry_cycles : 50
INFO 2024-07-12 09:44:09,157 - iso15118.evcc.evcc_config (121): max_contract_certs : 3
INFO 2024-07-12 09:44:09,158 - iso15118.evcc.evcc_config (121): enforce_tls : False
INFO 2024-07-12 09:44:09,158 - iso15118.evcc.evcc_config (121): supported_protocols : [<Protocol.ISO_15118_20_DC: (<Namespace.ISO_V20_DC: 'urn:iso:std:iso:15118:-20:DC'>, <enum 'ISOV20PayloadTypes'>)>]
INFO 2024-07-12 09:44:09,158 - iso15118.evcc.evcc_config (121): energy_transfer_mode : EnergyTransferModeEnum.DC_EXTENDED
INFO 2024-07-12 09:44:09,158 - iso15118.evcc.evcc_config (121): max_supporting_points : 1024
INFO 2024-07-12 09:44:09,158 - iso15118.evcc.evcc_config (121): charge_loop_cycle : 10
INFO 2024-07-12 09:44:20,008 - iso15118.shared.exi_codec (177): EXI Codec version: 1.55
INFO 2024-07-12 09:44:20,009 - iso15118.evcc (30): Starting 15118 version: 0.28.3
INFO 2024-07-12 09:44:20,009 - iso15118.evcc.comm_session_handler (311): Communication session handler started
DEBUG 2024-07-12 09:44:20,011 - iso15118.evcc.comm_session_handler (390): Initiating new SDP cycle, 49 more cycles(s) left
INFO 2024-07-12 09:44:20,011 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 50
DEBUG 2024-07-12 09:44:20,011 - iso15118.evcc.transport.udp_client (90): UDP client socket ready
INFO 2024-07-12 09:44:20,112 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:20,113 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
INFO 2024-07-12 09:44:20,149 - iso15118.evcc.transport.udp_client (105): Received datagram from UDP server at address ('fe80::ba27:ebff:fe98:a2bb', 15118, 0, 2)
INFO 2024-07-12 09:44:20,151 - iso15118.evcc.comm_session_handler (483): SDPResponse received: [ IP address: fe80::ba27:ebff:fe98:a2bb, Port: 56947 , Security: NO_TLS , Transport: TCP ]
INFO 2024-07-12 09:44:20,151 - iso15118.evcc.comm_session_handler (414): Starting TCP client, trying to connect to fe80::ba27:ebff:fe98:a2bb at port 56947 ...
INFO 2024-07-12 09:44:20,159 - iso15118.evcc.comm_session_handler (421): TCP client connected
INFO 2024-07-12 09:44:20,214 - iso15118.shared.comm_session (344): Starting a new communication session
INFO 2024-07-12 09:44:20,214 - iso15118.shared.states (139): Entered state SupportedAppProtocol
DEBUG 2024-07-12 09:44:20,215 - iso15118.shared.states (143): Waiting for up to Timeouts.SUPPORTED_APP_PROTOCOL_REQ s
INFO 2024-07-12 09:44:20,216 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.SAP): {"supportedAppProtocolReq": {"AppProtocol": [{"ProtocolNamespace": "urn:iso:std:iso:15118:-20:DC", "VersionNumberMajor": 1, "VersionNumberMinor": 0, "SchemaID": 1, "Priority": 1}]}}
INFO 2024-07-12 09:44:20,544 - iso15118.shared.comm_session (431): Sent supportedAppProtocolReq
INFO 2024-07-12 09:44:22,053 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.SAP): {"supportedAppProtocolRes":{"ResponseCode":"OK_SuccessfulNegotiation","SchemaID":1}}
INFO 2024-07-12 09:44:22,054 - iso15118.shared.comm_session (235): supportedAppProtocolRes received
INFO 2024-07-12 09:44:22,056 - iso15118.evcc.states.sap_states (155): Chosen protocol: ISO_15118_20_DC
INFO 2024-07-12 09:44:22,058 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"SessionSetupReq": {"Header": {"SessionID": "0000000000000000", "TimeStamp": 1720748662}, "EVCCID": "WMIV1234567890ABCDEX"}}
INFO 2024-07-12 09:44:23,900 - iso15118.shared.comm_session (431): Sent SessionSetupReq
INFO 2024-07-12 09:44:23,901 - iso15118.shared.states (139): Entered state SessionSetup
DEBUG 2024-07-12 09:44:23,901 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 09:44:25,904 - iso15118.shared.comm_session (395): The data link will SessionStopAction.TERMINATE in 2 seconds and the TCP connection will close in 5 seconds.
INFO 2024-07-12 09:44:25,905 - iso15118.shared.comm_session (399): Reason: TimeoutError occurred. Waited for Timeouts.SESSION_SETUP_REQ s after sending last message: [Header = [0x1, 0xfe, 0x8002, 39], Payload = 808c0400000000000000000f694c2b40620b2ba6a4ab1899199a1a9b1b9c1c9820a121a222ac00)]
INFO 2024-07-12 09:44:27,907 - iso15118.shared.comm_session (410): SessionStopAction.TERMINATEd the data link
INFO 2024-07-12 09:44:30,912 - iso15118.shared.comm_session (417): TCP connection closed to peer with address ('fe80::ba27:ebff:fe98:a2bb', 56947, 0, 2)
DEBUG 2024-07-12 09:44:30,913 - iso15118.evcc.comm_session_handler (390): Initiating new SDP cycle, 48 more cycles(s) left
INFO 2024-07-12 09:44:30,914 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 50
INFO 2024-07-12 09:44:30,914 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:30,915 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:31,167 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:31,168 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 49
INFO 2024-07-12 09:44:31,169 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:31,169 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:31,421 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:31,422 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 48
INFO 2024-07-12 09:44:31,423 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:31,424 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:31,675 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:31,676 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 47
INFO 2024-07-12 09:44:31,677 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:31,678 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:31,929 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:31,930 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 46
INFO 2024-07-12 09:44:31,931 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:31,932 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:32,183 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:32,184 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 45
INFO 2024-07-12 09:44:32,185 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:32,185 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:32,437 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:32,438 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 44
INFO 2024-07-12 09:44:32,439 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:32,440 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:32,691 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:32,692 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 43
INFO 2024-07-12 09:44:32,693 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:32,693 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:32,945 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:32,946 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 42
INFO 2024-07-12 09:44:32,947 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:32,947 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:33,199 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:33,200 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 41
INFO 2024-07-12 09:44:33,200 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:33,201 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:33,453 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:33,454 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 40
INFO 2024-07-12 09:44:33,454 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:33,455 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:33,707 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:33,707 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 39
INFO 2024-07-12 09:44:33,708 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:33,709 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:33,960 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:33,961 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 38
INFO 2024-07-12 09:44:33,962 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:33,963 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:34,214 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:34,215 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 37
INFO 2024-07-12 09:44:34,216 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:34,217 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:34,468 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:34,469 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 36
INFO 2024-07-12 09:44:34,470 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:34,471 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:34,722 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:34,723 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 35
INFO 2024-07-12 09:44:34,724 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:34,724 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:34,976 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:34,977 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 34
INFO 2024-07-12 09:44:34,977 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:34,978 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:35,230 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:35,231 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 33
INFO 2024-07-12 09:44:35,232 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:35,232 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:35,484 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:35,485 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 32
INFO 2024-07-12 09:44:35,486 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:35,486 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:35,738 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:35,739 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 31
INFO 2024-07-12 09:44:35,739 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:35,740 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:44:35,992 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:44:35,993 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 30
INFO 2024-07-12 09:44:35,993 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:44:35,994 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
INFO 2024-07-12 09:44:36,018 - iso15118.evcc.transport.udp_client (105): Received datagram from UDP server at address ('fe80::ba27:ebff:fe98:a2bb', 15118, 0, 2)
INFO 2024-07-12 09:44:36,019 - iso15118.evcc.comm_session_handler (483): SDPResponse received: [ IP address: fe80::ba27:ebff:fe98:a2bb, Port: 56947 , Security: NO_TLS , Transport: TCP ]
INFO 2024-07-12 09:44:36,020 - iso15118.evcc.comm_session_handler (414): Starting TCP client, trying to connect to fe80::ba27:ebff:fe98:a2bb at port 56947 ...
INFO 2024-07-12 09:44:36,029 - iso15118.evcc.comm_session_handler (421): TCP client connected
INFO 2024-07-12 09:44:36,030 - iso15118.shared.comm_session (344): Starting a new communication session
INFO 2024-07-12 09:44:36,030 - iso15118.shared.states (139): Entered state SupportedAppProtocol
DEBUG 2024-07-12 09:44:36,031 - iso15118.shared.states (143): Waiting for up to Timeouts.SUPPORTED_APP_PROTOCOL_REQ s
INFO 2024-07-12 09:44:36,033 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.SAP): {"supportedAppProtocolReq": {"AppProtocol": [{"ProtocolNamespace": "urn:iso:std:iso:15118:-20:DC", "VersionNumberMajor": 1, "VersionNumberMinor": 0, "SchemaID": 1, "Priority": 1}]}}
INFO 2024-07-12 09:44:36,061 - iso15118.shared.comm_session (431): Sent supportedAppProtocolReq
INFO 2024-07-12 09:44:36,132 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.SAP): {"supportedAppProtocolRes":{"ResponseCode":"OK_SuccessfulNegotiation","SchemaID":1}}
INFO 2024-07-12 09:44:36,132 - iso15118.shared.comm_session (235): supportedAppProtocolRes received
INFO 2024-07-12 09:44:36,136 - iso15118.evcc.states.sap_states (155): Chosen protocol: ISO_15118_20_DC
INFO 2024-07-12 09:44:36,137 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"SessionSetupReq": {"Header": {"SessionID": "0000000000000000", "TimeStamp": 1720748676}, "EVCCID": "WMIV1234567890ABCDEX"}}
INFO 2024-07-12 09:44:36,966 - iso15118.shared.comm_session (431): Sent SessionSetupReq
INFO 2024-07-12 09:44:36,966 - iso15118.shared.states (139): Entered state SessionSetup
DEBUG 2024-07-12 09:44:36,967 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_COMMUNICATION_SETUP_TIMEOUT s
INFO 2024-07-12 09:44:39,099 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.ISO_V20_COMMON_MSG): {"SessionSetupRes":{"Header":{"SessionID":"00C0AD61A696C9E6","TimeStamp":1720748677},"ResponseCode":"OK_NewSessionEstablished","EVSEID":"UK123E1234"}}
INFO 2024-07-12 09:44:39,100 - iso15118.shared.comm_session (235): SessionSetupRes received
INFO 2024-07-12 09:44:39,102 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"AuthorizationSetupReq": {"Header": {"SessionID": "00C0AD61A696C9E6", "TimeStamp": 1720748679}}}
INFO 2024-07-12 09:44:39,731 - iso15118.shared.comm_session (431): Sent AuthorizationSetupReq
INFO 2024-07-12 09:44:39,732 - iso15118.shared.states (139): Entered state AuthorizationSetup
DEBUG 2024-07-12 09:44:39,732 - iso15118.shared.states (143): Waiting for up to Timeouts.SESSION_SETUP_REQ s
INFO 2024-07-12 09:44:41,565 - iso15118.shared.exi_codec (302): Decoded message (ns=Namespace.ISO_V20_COMMON_MSG): {"AuthorizationSetupRes":{"Header":{"SessionID":"00C0AD61A696C9E6","TimeStamp":1720748680},"ResponseCode":"OK","AuthorizationServices":["PnC","EIM"],"CertificateInstallationService":true,"PnC_ASResAuthorizationMode":{"GenChallenge":"gQmoAjrjQw/N1J0d52pKrg=="}}}
INFO 2024-07-12 09:44:41,567 - iso15118.shared.comm_session (235): AuthorizationSetupRes received
INFO 2024-07-12 09:44:41,580 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"PnC_AReqAuthorizationMode": {"Id": "id1", "GenChallenge": "gQmoAjrjQw/N1J0d52pKrg==", "ContractCertificateChain": {"Certificate": "MIICYzCCAgmgAwIBAgICMEQwCgYIKoZIzj0EAwIwVjEiMCAGA1UEAwwZUEtJLUV4dF9DUlRfTU9fU1VCMl9WQUxJRDEPMA0GA1UECgwGU3dpdGNoMQswCQYDVQQGEwJVSzESMBAGCgmSJomT8ixkARkWAk1PMB4XDTI0MDcwOTA2MzY1NloXDTI2MDcwOTA2MzY1NlowTDEYMBYGA1UEAwwPVUtTV0kxMjM0NTY3OTFBMQ8wDQYDVQQKDAZTd2l0Y2gxCzAJBgNVBAYTAlVLMRIwEAYKCZImiZPyLGQBGRYCTU8wWTATBgcqhkjOPQIBBggqhkjOPQMBBwNCAAQffldsrjZD+Be6rFiuUsMUTVTloHzuufaJwSfAU59CUlFCZXqiqaalipZU8dEDH1u1YIlV7vFaQ8wINsLpqegio4HQMIHNMAwGA1UdEwEB/wQCMAAwDgYDVR0PAQH/BAQDAgPoMB0GA1UdDgQWBBTADLrH5LX/pHerGrjFdIJi0wFU3TBtBggrBgEFBQcBAQRhMF8wJAYIKwYBBQUHMAGGGGh0dHBzOi8vd3d3LmV4YW1wbGUuY29tLzA3BggrBgEFBQcwAoYraHR0cHM6Ly93d3cuZXhhbXBsZS5jb20vSW50ZXJtZWRpYXRlLUNBLmNlcjAfBgNVHSMEGDAWgBRBmoV4bmT1Gei9SzvKEp1FNxLNzTAKBggqhkjOPQQDAgNIADBFAiEAzXZyMT+5jXh33rNe3pVgH3eq+56VvraPfJymhp1DtUcCIG/eUqUcUX594/cOyhYMOdfsCNlHEGGfeK8h7Yj6Z86s", "SubCertificates": {"Certificate": ["MIICdDCCAhmgAwIBAgICMEMwCgYIKoZIzj0EAwIwVjEiMCAGA1UEAwwZUEtJLUV4dF9DUlRfTU9fU1VCMV9WQUxJRDEPMA0GA1UECgwGU3dpdGNoMQswCQYDVQQGEwJVSzESMBAGCgmSJomT8ixkARkWAk1PMB4XDTI0MDcwOTA2MzY1NVoXDTI4MDcwODA2MzY1NVowVjEiMCAGA1UEAwwZUEtJLUV4dF9DUlRfTU9fU1VCMl9WQUxJRDEPMA0GA1UECgwGU3dpdGNoMQswCQYDVQQGEwJVSzESMBAGCgmSJomT8ixkARkWAk1PMFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEF5wTCTsazn97fGUt4+D5pUouBDD9D14GzaoK9tzcn5K2uau2VxRWmdZ5C7ivsawHHCjec4dOdc9S4s9Fd0vuIqOB1jCB0zASBgNVHRMBAf8ECDAGAQH/AgEAMA4GA1UdDwEB/wQEAwIBxjAdBgNVHQ4EFgQUQZqFeG5k9RnovUs7yhKdRTcSzc0wbQYIKwYBBQUHAQEEYTBfMCQGCCsGAQUFBzABhhhodHRwczovL3d3dy5leGFtcGxlLmNvbS8wNwYIKwYBBQUHMAKGK2h0dHBzOi8vd3d3LmV4YW1wbGUuY29tL0ludGVybWVkaWF0ZS1DQS5jZXIwHwYDVR0jBBgwFoAUz94C3f6kUKnLtKCw7KEBp/UeD6AwCgYIKoZIzj0EAwIDSQAwRgIhAKBrU/LIklLY5cU0RAvzGwmce4reavaJpc5hR8hireFYAiEA4PvmHfH0ml7esZ00yIC8IfNExykQarIgaS8qJNewux4=", "MIICYzCCAgigAwIBAgICMEIwCgYIKoZIzj0EAwIwRTERMA8GA1UEAwwITU9Sb290Q0ExDzANBgNVBAoMBlN3aXRjaDELMAkGA1UEBhMCVUsxEjAQBgoJkiaJk/IsZAEZFgJNTzAeFw0yNDA3MDkwNjM2NTVaFw0yODA3MDgwNjM2NTVaMFYxIjAgBgNVBAMMGVBLSS1FeHRfQ1JUX01PX1NVQjFfVkFMSUQxDzANBgNVBAoMBlN3aXRjaDELMAkGA1UEBhMCVUsxEjAQBgoJkiaJk/IsZAEZFgJNTzBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IABGe2qW9s+6QIIjNHlYz3m1QRqyhAsKaPDjh2jgkFk0k8u8Lu+JDw70nhDqACiC7x37+pODDQQFF8BVwXWPm5g1SjgdYwgdMwEgYDVR0TAQH/BAgwBgEB/wIBATAOBgNVHQ8BAf8EBAMCAQYwHQYDVR0OBBYEFM/eAt3+pFCpy7SgsOyhAaf1Hg+gMG0GCCsGAQUFBwEBBGEwXzAkBggrBgEFBQcwAYYYaHR0cHM6Ly93d3cuZXhhbXBsZS5jb20vMDcGCCsGAQUFBzAChitodHRwczovL3d3dy5leGFtcGxlLmNvbS9JbnRlcm1lZGlhdGUtQ0EuY2VyMB8GA1UdIwQYMBaAFOQmuNkKcbIP/1cgj5mTLddHTGtpMAoGCCqGSM49BAMCA0kAMEYCIQC6zrxMqygx/cTc3l206/fqDgybbYsxH/1r/s3rrrSNwAIhAPEO+L8WaVcBB0PFtjUMtxb80iTiZ9jInX0O8igjV52K"]}}}}
INFO 2024-07-12 09:44:42,369 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.XML_DSIG): {"SignedInfo": {"CanonicalizationMethod": {"Algorithm": "http://www.w3.org/TR/canonical-exi/"}, "SignatureMethod": {"Algorithm": "http://www.w3.org/2001/04/xmldsig-more#ecdsa-sha512"}, "Reference": [{"Transforms": {"Transform": [{"Algorithm": "http://www.w3.org/TR/canonical-exi/"}]}, "DigestMethod": {"Algorithm": "http://www.w3.org/2001/04/xmlenc#sha512"}, "DigestValue": "9GauetvhVLGDqEaMtwWo8KlWBBGWe2SohTnU8p0JzZfCSCNZVRFfREQOkb40VFag7L1+HjeATXnT1hytnoDikg==", "URI": "#id1"}]}}
INFO 2024-07-12 09:44:42,869 - iso15118.shared.exi_codec (248): Message to encode (ns=Namespace.ISO_V20_COMMON_MSG): {"AuthorizationReq": {"Header": {"SessionID": "00C0AD61A696C9E6", "TimeStamp": 1720748682, "Signature": {"SignedInfo": {"CanonicalizationMethod": {"Algorithm": "http://www.w3.org/TR/canonical-exi/"}, "SignatureMethod": {"Algorithm": "http://www.w3.org/2001/04/xmldsig-more#ecdsa-sha512"}, "Reference": [{"Transforms": {"Transform": [{"Algorithm": "http://www.w3.org/TR/canonical-exi/"}]}, "DigestMethod": {"Algorithm": "http://www.w3.org/2001/04/xmlenc#sha512"}, "DigestValue": "9GauetvhVLGDqEaMtwWo8KlWBBGWe2SohTnU8p0JzZfCSCNZVRFfREQOkb40VFag7L1+HjeATXnT1hytnoDikg==", "URI": "#id1"}]}, "SignatureValue": {"value": "AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABhBByXmJjbdkjvUQ2UBrAnyQbPT/r+gC2cEHDQDXEs1AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAADBacchuu3sEzmHwzmWfMLtqwgKE9PyQmspm5AaPTQUz"}}}, "SelectedAuthorizationService": "PnC", "PnC_AReqAuthorizationMode": {"Id": "id1", "GenChallenge": "gQmoAjrjQw/N1J0d52pKrg==", "ContractCertificateChain": {"Certificate": "MIICYzCCAgmgAwIBAgICMEQwCgYIKoZIzj0EAwIwVjEiMCAGA1UEAwwZUEtJLUV4dF9DUlRfTU9fU1VCMl9WQUxJRDEPMA0GA1UECgwGU3dpdGNoMQswCQYDVQQGEwJVSzESMBAGCgmSJomT8ixkARkWAk1PMB4XDTI0MDcwOTA2MzY1NloXDTI2MDcwOTA2MzY1NlowTDEYMBYGA1UEAwwPVUtTV0kxMjM0NTY3OTFBMQ8wDQYDVQQKDAZTd2l0Y2gxCzAJBgNVBAYTAlVLMRIwEAYKCZImiZPyLGQBGRYCTU8wWTATBgcqhkjOPQIBBggqhkjOPQMBBwNCAAQffldsrjZD+Be6rFiuUsMUTVTloHzuufaJwSfAU59CUlFCZXqiqaalipZU8dEDH1u1YIlV7vFaQ8wINsLpqegio4HQMIHNMAwGA1UdEwEB/wQCMAAwDgYDVR0PAQH/BAQDAgPoMB0GA1UdDgQWBBTADLrH5LX/pHerGrjFdIJi0wFU3TBtBggrBgEFBQcBAQRhMF8wJAYIKwYBBQUHMAGGGGh0dHBzOi8vd3d3LmV4YW1wbGUuY29tLzA3BggrBgEFBQcwAoYraHR0cHM6Ly93d3cuZXhhbXBsZS5jb20vSW50ZXJtZWRpYXRlLUNBLmNlcjAfBgNVHSMEGDAWgBRBmoV4bmT1Gei9SzvKEp1FNxLNzTAKBggqhkjOPQQDAgNIADBFAiEAzXZyMT+5jXh33rNe3pVgH3eq+56VvraPfJymhp1DtUcCIG/eUqUcUX594/cOyhYMOdfsCNlHEGGfeK8h7Yj6Z86s", "SubCertificates": {"Certificate": ["MIICdDCCAhmgAwIBAgICMEMwCgYIKoZIzj0EAwIwVjEiMCAGA1UEAwwZUEtJLUV4dF9DUlRfTU9fU1VCMV9WQUxJRDEPMA0GA1UECgwGU3dpdGNoMQswCQYDVQQGEwJVSzESMBAGCgmSJomT8ixkARkWAk1PMB4XDTI0MDcwOTA2MzY1NVoXDTI4MDcwODA2MzY1NVowVjEiMCAGA1UEAwwZUEtJLUV4dF9DUlRfTU9fU1VCMl9WQUxJRDEPMA0GA1UECgwGU3dpdGNoMQswCQYDVQQGEwJVSzESMBAGCgmSJomT8ixkARkWAk1PMFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEF5wTCTsazn97fGUt4+D5pUouBDD9D14GzaoK9tzcn5K2uau2VxRWmdZ5C7ivsawHHCjec4dOdc9S4s9Fd0vuIqOB1jCB0zASBgNVHRMBAf8ECDAGAQH/AgEAMA4GA1UdDwEB/wQEAwIBxjAdBgNVHQ4EFgQUQZqFeG5k9RnovUs7yhKdRTcSzc0wbQYIKwYBBQUHAQEEYTBfMCQGCCsGAQUFBzABhhhodHRwczovL3d3dy5leGFtcGxlLmNvbS8wNwYIKwYBBQUHMAKGK2h0dHBzOi8vd3d3LmV4YW1wbGUuY29tL0ludGVybWVkaWF0ZS1DQS5jZXIwHwYDVR0jBBgwFoAUz94C3f6kUKnLtKCw7KEBp/UeD6AwCgYIKoZIzj0EAwIDSQAwRgIhAKBrU/LIklLY5cU0RAvzGwmce4reavaJpc5hR8hireFYAiEA4PvmHfH0ml7esZ00yIC8IfNExykQarIgaS8qJNewux4=", "MIICYzCCAgigAwIBAgICMEIwCgYIKoZIzj0EAwIwRTERMA8GA1UEAwwITU9Sb290Q0ExDzANBgNVBAoMBlN3aXRjaDELMAkGA1UEBhMCVUsxEjAQBgoJkiaJk/IsZAEZFgJNTzAeFw0yNDA3MDkwNjM2NTVaFw0yODA3MDgwNjM2NTVaMFYxIjAgBgNVBAMMGVBLSS1FeHRfQ1JUX01PX1NVQjFfVkFMSUQxDzANBgNVBAoMBlN3aXRjaDELMAkGA1UEBhMCVUsxEjAQBgoJkiaJk/IsZAEZFgJNTzBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IABGe2qW9s+6QIIjNHlYz3m1QRqyhAsKaPDjh2jgkFk0k8u8Lu+JDw70nhDqACiC7x37+pODDQQFF8BVwXWPm5g1SjgdYwgdMwEgYDVR0TAQH/BAgwBgEB/wIBATAOBgNVHQ8BAf8EBAMCAQYwHQYDVR0OBBYEFM/eAt3+pFCpy7SgsOyhAaf1Hg+gMG0GCCsGAQUFBwEBBGEwXzAkBggrBgEFBQcwAYYYaHR0cHM6Ly93d3cuZXhhbXBsZS5jb20vMDcGCCsGAQUFBzAChitodHRwczovL3d3dy5leGFtcGxlLmNvbS9JbnRlcm1lZGlhdGUtQ0EuY2VyMB8GA1UdIwQYMBaAFOQmuNkKcbIP/1cgj5mTLddHTGtpMAoGCCqGSM49BAMCA0kAMEYCIQC6zrxMqygx/cTc3l206/fqDgybbYsxH/1r/s3rrrSNwAIhAPEO+L8WaVcBB0PFtjUMtxb80iTiZ9jInX0O8igjV52K"]}}}}}
INFO 2024-07-12 09:44:43,324 - iso15118.shared.comm_session (431): Sent AuthorizationReq
INFO 2024-07-12 09:44:43,325 - iso15118.shared.states (139): Entered state Authorization
DEBUG 2024-07-12 09:44:43,325 - iso15118.shared.states (143): Waiting for up to Timeouts.V2G_EVCC_ONGOING_TIMEOUT s
INFO 2024-07-12 09:45:43,364 - iso15118.shared.comm_session (395): The data link will SessionStopAction.TERMINATE in 2 seconds and the TCP connection will close in 5 seconds.
INFO 2024-07-12 09:45:43,365 - iso15118.shared.comm_session (399): Reason: TimeoutError occurred. Waited for Timeouts.V2G_EVCC_ONGOING_TIMEOUT s after sending last message: [Header = [0x1, 0xfe, 0x8002, 2283], Payload = 800004006056b0d34b64f308a95c2b4060a25687474703a2f2f7777772e77332e6f72672f54522f63616e6f6e6963616c2d6578692f435687474703a2f2f7777772e77332e6f72672f323030312f30342f786d6c647369672d6d6f72652365636473612d736861353132440c46d2c86204ad0e8e8e0745e5eeeeeee5cee665cdee4ce5ea8a45ec6c2dcdedcd2c6c2d85acaf0d25e90a5a1d1d1c0e8bcbddddddcb9dcccb9bdc99cbcc8c0c0c4bcc0d0bde1b5b195b98c8dcda184d4c4c9103d19ab9eb6f8552c60ea11a32dc16a3c2a558104659ed92a214e753ca7427365f09208d6554457d11103a46f8d1515a83b2f5f878de0135e74f5872b67a038a484c200800000000000000000000000000000000000000000000000000000000000000000000c208392f3131b6ec91dea21b280d604f920d9e9ff5fd005b3820e1a01ae259a80000000000000000000000000000000000000000000000000000000000000000000182d38e4375dbd826730f86732cf985db56101427a7e484d6533720347a68299a12056964310420426a008eb8d0c3f375274779da92ab839c10c208098cc2080826800c0804080808c110c0281820aa192338f4100c08c158c488c080180d54100c3065412d24b515e1d17d0d49517d353d7d4d5508c97d5905312510c43cc034180d54102830194ddda5d18da0c42cc024180d5410184c09552cc448c040182826489a264fc8b19004645809353cc0785c34c8d0c0dcc0e4c0d8ccd8d4d9685c34c8d8c0dcc0e4c0d8ccd8d4d968c130c460c058180d54100c303d552d4d5d24c4c8ccd0d4d8dce4c504c43cc034180d54102830194ddda5d18da0c42cc024180d5410184c09552cc448c040182826489a264fc8b19004645809353cc164c04c181caa192338f408041820aa192338f40c041c0d0800107df95db2b8d90fe05eeab162b94b0c5135539681f3bae7da27049f014e7d0949450995ea8aa69a962a5953c7440c7d6ed5822557bbc5690f3020db0ba6a7a08a8e0740c20734c030180d54744c0407fc1008c000c038180d54743c0407fc10100c080fa0c074180d547438105810530032eb1f92d7fe91deac6ae315d2098b4c055374c1b41820ac180414141c04041184c17cc0901820ac180414141cc0061861a1d1d1c1cce8bcbddddddcb995e185b5c1b194b98dbdb4bcc0dc1820ac180414141cc00a18ada1d1d1c1cce8bcbddddddcb995e185b5c1b194b98dbdb4bd25b9d195c9b59591a585d194b50d04b98d95c8c07c180d54748c1060c05a0051066a15e1b993d467a2f52cef284a7514dc4b3734c0281820aa192338f4100c080d2000c11408840335d9c8c4fee635e1df7acd7b7a55807ddeabee7a56fada3df2729a1a750ed51c0881bf794a947145f9f78fdc3b285830e75fb023651c41867de2bc87b623e99f3ab03e010c20809d0c2080866800c0804080808c10cc0281820aa192338f4100c08c158c488c080180d54100c3065412d24b515e1d17d0d49517d353d7d4d5508c57d5905312510c43cc034180d54102830194ddda5d18da0c42cc024180d5410184c09552cc448c040182826489a264fc8b19004645809353cc0785c34c8d0c0dcc0e4c0d8ccd8d4d5685c34c8e0c0dcc0e0c0d8ccd8d4d568c158c488c080180d54100c3065412d24b515e1d17d0d49517d353d7d4d5508c97d5905312510c43cc034180d54102830194ddda5d18da0c42cc024180d5410184c09552cc448c040182826489a264fc8b19004645809353cc164c04c181caa192338f408041820aa192338f40c041c0d0800105e704c24ec6b39fdedf194b78f83e69528b810c3f43d781b36a82bdb73727e4adae6aed95c515a6759e42ee2bec6b01c70a379ce1d39d73d4b8b3d15dd2fb88a8e0758c2074cc048180d54744c0407fc1020c0180407fc080400c038180d54743c0407fc10100c080718c074180d54743810581051066a15e1b993d467a2f52cef284a7514dc4b3734c1b41820ac180414141c04041184c17cc0901820ac180414141cc0061861a1d1d1c1cce8bcbddddddcb995e185b5c1b194b98dbdb4bcc0dc1820ac180414141cc00a18ada1d1d1c1cce8bcbddddddcb995e185b5c1b194b98dbdb4bd25b9d195c9b59591a585d194b50d04b98d95c8c07c180d54748c1060c05a00533f780b77fa9142a72ed282c3b284069fd4783e80c0281820aa192338f4100c080d2400c11808840281ad4fcb22494b639714d1102fcc6c2671ee2b79abda269739851f218ab7856008840383ef9877c7d2697b7ac674d32202f087cd131ca441aac881a4bca8935ec2ec7839c10c208098cc2080822800c0804080808c108c0281820aa192338f4100c08c114c444c03c180d54100c3021353d49bdbdd10d04c43cc034180d54102830194ddda5d18da0c42cc024180d5410184c09552cc448c040182826489a264fc8b19004645809353cc0785c34c8d0c0dcc0e4c0d8ccd8d4d5685c34c8e0c0dcc0e0c0d8ccd8d4d568c158c488c080180d54100c3065412d24b515e1d17d0d49517d353d7d4d5508c57d5905312510c43cc034180d54102830194ddda5d18da0c42cc024180d5410184c09552cc448c040182826489a264fc8b19004645809353cc164c04c181caa192338f408041820aa192338f40c041c0d0800119edaa5bdb3ee902088cd1e5633de6d5046aca102c29a3c38e1da3824164d24f2ef0bbbe243c3bd27843a800a20bbc77efea4e0c3410145f015705d63e6e60d528e0758c2074cc048180d54744c0407fc1020c0180407fc080404c038180d54743c0407fc10100c080418c074180d547438105810533f780b77fa9142a72ed282c3b284069fd4783e80c1b41820ac180414141c04041184c17cc0901820ac180414141cc0061861a1d1d1c1cce8bcbddddddcb995e185b5c1b194b98dbdb4bcc0dc1820ac180414141cc00a18ada1d1d1c1cce8bcbddddddcb995e185b5c1b194b98dbdb4bd25b9d195c9b59591a585d194b50d04b98d95c8c07c180d54748c1060c05a0053909ae36429c6c83ffd5c823e664cb75d1d31ada4c0281820aa192338f4100c080d2400c118088402eb3af132aca0c7f713737976d3afdfa838326db62cc47ff5affb37aebad23700088403c43be2fc59a55c041d0f16d8d432dc5bf34893899f632275f43bc8a08d5e762880)]
INFO 2024-07-12 09:45:45,701 - iso15118.shared.comm_session (410): SessionStopAction.TERMINATEd the data link
INFO 2024-07-12 09:45:48,707 - iso15118.shared.comm_session (417): TCP connection closed to peer with address ('fe80::ba27:ebff:fe98:a2bb', 56947, 0, 2)
DEBUG 2024-07-12 09:45:48,708 - iso15118.evcc.comm_session_handler (390): Initiating new SDP cycle, 47 more cycles(s) left
INFO 2024-07-12 09:45:48,709 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 50
INFO 2024-07-12 09:45:48,709 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:45:48,710 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:45:48,962 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:45:48,963 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 49
INFO 2024-07-12 09:45:48,964 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:45:48,964 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]

INFO 2024-07-12 09:46:00,899 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 2
INFO 2024-07-12 09:46:00,899 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:46:00,900 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:46:01,152 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
INFO 2024-07-12 09:46:01,153 - iso15118.evcc.comm_session_handler (396): Remaining SDP requests: 1
INFO 2024-07-12 09:46:01,153 - iso15118.evcc.comm_session_handler (333): Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]
DEBUG 2024-07-12 09:46:01,154 - iso15118.evcc.transport.udp_client (170): Message sent: [Header = [0x1, 0xfe, 0x9000, 2], Payload = 1000)]
WARNING 2024-07-12 09:46:01,406 - iso15118.evcc.transport.udp_client (179): A TimeoutError occurred. Waited for Timeouts.SDP_REQ s after sending an SDPRequest
ERROR 2024-07-12 09:46:01,407 - iso15118.evcc.comm_session_handler (556): SDPRequest was not successful. Shutting down high-level communication. Unplug and plug in the cable again if you want to start anew.

iso15118.shared.exceptions.SDPFailedError: SDPRequest was not successful. Shutting down high-level communication. Unplug and plug in the cable again if you want to start anew