Implementation of the ISO 15118 Communication Protocol (-2, -20, -8)
Apache License 2.0
156
stars
86
forks
source link
Running Josev/ISO15118 local with ISO15118-20 dc config JSON file on Raspberry Pi: EVCC terminates data link after Timeouts_EVCC_ONGOING_TIMEOUT s #427
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
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