dallmann-consulting / OCPP.Core

OCPP server and management UI written in .NET-Core
GNU General Public License v3.0
203 stars 83 forks source link

[Hager Witty Park / 1.0.0.0 / 9.0.1.0] Stop charging look not working #55

Open TenGbps opened 2 months ago

TenGbps commented 2 months ago

Capture d’écran 2024-04-29 à 15 12 25 Can you help me understand why I never get an end of charge?

Logs on my Hager Witty Park : [2024-04-29 05:26:18] Connector 3: Cable connection [2024-04-29 05:26:18] Connector 3: OCPP Status Preparing [2024-04-29 05:26:18] Connector 3: Cable 32 A [2024-04-29 05:26:23] Connector 3: Vehicle connection [2024-04-29 05:27:03] RFID tag: XXXXXXX1 [2024-04-29 05:27:03] Authorize (tag = XXXXXXX1, status = Accepted, expiry date = 2024-04-29T05:32:03Z) [2024-04-29 05:27:04] Connector 3: Suspended EVSE [2024-04-29 05:27:04] Connector 3: OCPP Status Suspended EVSE [2024-04-29 05:27:05] Connector 3: Suspended EV [2024-04-29 05:27:05] Connector 3: OCPP Status Suspended EV [2024-04-29 05:27:11] Connector 3: Charging [2024-04-29 05:27:11] Connector 3: OCPP Status Charging [2024-04-29 05:27:14] Connector 3: OCPP Status Charging [2024-04-29 09:09:16] Connector 3: Suspended EV [2024-04-29 09:09:16] Connector 3: OCPP Status Suspended EV [2024-04-29 10:31:46] Connector 3: Vehicle disconnection [2024-04-29 10:31:46] Connector 3: OCPP Status Finishing [2024-04-29 10:31:53] Connector 3: Cable disconnection [2024-04-29 10:31:53] Connector 3: OCPP Status Available

dallmann-consulting commented 2 months ago

Hi, it seems like this is the same behavior like issue #47 . The charger most probably doesn't send a "StopTransaction" message. The usual process is:

1.) The charger sends an "Authorize" massage when an RFID-tag is presented. 2.) The server responds with accepted. 3.) When a car is connected, the charger sends a StartTransaction message. 4.) The server stores the transaction (ID + meter value) and accepts the transaction for the specific connector. 5.) The charger periodically sends meter value and can also send status messages (like suspended etc.) 6.) The charger sends a StopTransaction message when the transaction is finally stopped. This message contains the stop meter value and can also contain signed data about the transaction. 7.) The charger send a status like no EV connected.

Your log above also doesn't show anything about a "StartTransaction" or StopTransaction message. The start message must have been sent. Otherwise no transaction would be running. But as the transactions are not stopped, the chargers probably doesn't send the expected stop message. Can you check the dump folder (where all massages are stored) if you find a StopTransaction method?

TenGbps commented 2 months ago

Searching in all dump StartTransaction Capture d’écran 2024-05-07 à 17 01 04

Searching in all dump StopTransaction Capture d’écran 2024-05-07 à 17 26 18

dallmann-consulting commented 2 months ago

OK. The charger sends a StopTransaction but this message lacks the required transaction id. It is always "-1".

From OCPP specification:

transactionId integer 1..1 Required. This contains the transaction-id as received by the StartTransaction.conf.

With OCPP 1.6 the servers answers the StartTransaction-Message with a generated transaction id (integer). The charger needs to send this back with the StopTransaction message. Your charger doesn't do this and then the server can't stop the transaction. The servers answer to these stop-messages is probably an error. You should see errors in the log files.

OCPP 2.0 changes the id handling, that the charger generates a UID as a transaction id and sends this with the start-message. Does your charger support OCPP 2.0? Maybe that works!?

TenGbps commented 2 months ago

ì have open a case to hager i waiting reply

Full dump in-out of transaction : 2024-05-15_16-29-15-5620_ocpp16-in.txt:[2, "819767f0-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Preparing","timestamp":"2024-05-15T14:29:15Z"}] 2024-05-15_16-29-16-2064_ocpp16-out.txt:[3,"819767f0-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-16-3552_ocpp16-in.txt:[2, "821ceba0-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":3,"errorCode":"NoError","status":"Preparing","timestamp":"2024-05-15T14:29:15Z"}] 2024-05-15_16-29-16-3657_ocpp16-out.txt:[3,"821ceba0-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-17-1209_ocpp16-in.txt:[2, "828f5c80-12c7-11ef-8012-0c8629738129", "Authorize", {"idTag":"ABCD1234"}] 2024-05-15_16-29-17-1532_ocpp16-out.txt:[3,"828f5c80-12c7-11ef-8012-0c8629738129",{"idTagInfo":{"expiryDate":"2024-05-15T14:34:17.1253835+00:00","parentIdTag":"charger","status":"Accepted"}}] 2024-05-15_16-29-17-4183_ocpp16-in.txt:[2, "82b58220-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"SuspendedEVSE","timestamp":"2024-05-15T14:29:17Z"}] 2024-05-15_16-29-17-4292_ocpp16-out.txt:[3,"82b58220-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-18-3871_ocpp16-in.txt:[2, "834e18a0-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Charging","timestamp":"2024-05-15T14:29:18Z"}] 2024-05-15_16-29-18-3959_ocpp16-out.txt:[3,"834e18a0-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-20-5423_ocpp16-in.txt:[2, "84925870-12c7-11ef-8012-0c8629738129", "StartTransaction", {"connectorId":4,"idTag":"ABCD1234","meterStart":51880,"timestamp":"2024-05-15T14:25:12Z"}] 2024-05-15_16-29-20-6023_ocpp16-out.txt:[3,"84925870-12c7-11ef-8012-0c8629738129",{"idTagInfo":{"expiryDate":"2199-12-31T00:00:00+01:00","parentIdTag":"charger","status":"ConcurrentTx"},"transactionId":0}] 2024-05-15_16-29-22-4483_ocpp16-in.txt:[2, "85c38570-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Finishing","timestamp":"2024-05-15T14:29:22Z"}] 2024-05-15_16-29-22-4573_ocpp16-out.txt:[3,"85c38570-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-24-0016_ocpp16-in.txt:[2, "86a86730-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":3,"errorCode":"NoError","status":"Available","timestamp":"2024-05-15T14:29:23Z"}] 2024-05-15_16-29-24-0105_ocpp16-out.txt:[3,"86a86730-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-24-1574_ocpp16-in.txt:[2, "86bb7a00-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Available","timestamp":"2024-05-15T14:29:23Z"}] 2024-05-15_16-29-24-1674_ocpp16-out.txt:[3,"86bb7a00-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-29-2199_ocpp16-in.txt:[2, "89c97d50-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Preparing","timestamp":"2024-05-15T14:29:29Z"}] 2024-05-15_16-29-29-2288_ocpp16-out.txt:[3,"89c97d50-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-29-3803_ocpp16-in.txt:[2, "89dc9020-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":3,"errorCode":"NoError","status":"Preparing","timestamp":"2024-05-15T14:29:29Z"}] 2024-05-15_16-29-29-3888_ocpp16-out.txt:[3,"89dc9020-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-31-2338_ocpp16-in.txt:[2, "8afaaa50-12c7-11ef-8012-0c8629738129", "Authorize", {"idTag":"ABCD1234"}] 2024-05-15_16-29-31-2362_ocpp16-out.txt:[3,"8afaaa50-12c7-11ef-8012-0c8629738129",{"idTagInfo":{"expiryDate":"2024-05-15T14:34:31.2351101+00:00","parentIdTag":"charger","status":"Accepted"}}] 2024-05-15_16-29-31-5014_ocpp16-in.txt:[2, "8b20cff0-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"SuspendedEVSE","timestamp":"2024-05-15T14:29:31Z"}] 2024-05-15_16-29-31-5120_ocpp16-out.txt:[3,"8b20cff0-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-32-4609_ocpp16-in.txt:[2, "8bb96670-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Charging","timestamp":"2024-05-15T14:29:32Z"}] 2024-05-15_16-29-32-4700_ocpp16-out.txt:[3,"8bb96670-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-38-8170_ocpp16-in.txt:[2, "8f8625e0-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Finishing","info":"EV side disconnected","timestamp":"2024-05-15T14:29:38Z"}] 2024-05-15_16-29-38-8260_ocpp16-out.txt:[3,"8f8625e0-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-38-9750_ocpp16-in.txt:[2, "8f9938b0-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":4,"errorCode":"NoError","status":"Available","timestamp":"2024-05-15T14:29:38Z"}] 2024-05-15_16-29-38-9833_ocpp16-out.txt:[3,"8f9938b0-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-39-1339_ocpp16-in.txt:[2, "8fac4b80-12c7-11ef-8012-0c8629738129", "StatusNotification", {"connectorId":3,"errorCode":"NoError","status":"Available","timestamp":"2024-05-15T14:29:38Z"}] 2024-05-15_16-29-39-1423_ocpp16-out.txt:[3,"8fac4b80-12c7-11ef-8012-0c8629738129",{}] 2024-05-15_16-29-41-5002_ocpp16-in.txt:[2, "9116b0f0-12c7-11ef-8012-0c8629738129", "StartTransaction", {"connectorId":4,"idTag":"ABCD1234","meterStart":51880,"timestamp":"2024-05-15T14:25:12Z"}] 2024-05-15_16-29-41-5125_ocpp16-out.txt:[3,"9116b0f0-12c7-11ef-8012-0c8629738129",{"idTagInfo":{"expiryDate":"2199-12-31T00:00:00+01:00","parentIdTag":"charger","status":"ConcurrentTx"},"transactionId":0}] 2024-05-15_16-29-42-4577_ocpp16-in.txt:[2, "91af4770-12c7-11ef-8012-0c8629738129", "Heartbeat", {}] 2024-05-15_16-29-42-4596_ocpp16-out.txt:[3,"91af4770-12c7-11ef-8012-0c8629738129",{"currentTime":"2024-05-15T14:29:42.4587962+00:00"}] 2024-05-15_16-29-42-6153_ocpp16-in.txt:[2, "91af4771-12c7-11ef-8013-0c8629738129", "MeterValues", {"connectorId":4,"meterValue":[{"timestamp":"2024-05-15T14:25:12Z","sampledValue":[{"value":"51880","context":"Transaction.Begin","format":"Raw","measurand":"Energy.Active.Import.Register","location":"Outlet","unit":"Wh"}]}],"transactionId":-1}] 2024-05-15_16-29-42-6462_ocpp16-out.txt:[3,"91af4771-12c7-11ef-8013-0c8629738129",{}] 2024-05-15_16-29-43-4904_ocpp16-in.txt:[2, "9247ddf0-12c7-11ef-8013-0c8629738129", "MeterValues", {"connectorId":4,"meterValue":[{"timestamp":"2024-05-15T14:25:17Z","sampledValue":[{"value":"51880","context":"Transaction.End","format":"Raw","measurand":"Energy.Active.Import.Register","location":"Outlet","unit":"Wh"}]}],"transactionId":-1}] 2024-05-15_16-29-43-5011_ocpp16-out.txt:[3,"9247ddf0-12c7-11ef-8013-0c8629738129",{}] 2024-05-15_16-29-44-5523_ocpp16-in.txt:[2, "92e07470-12c7-11ef-8013-0c8629738129", "StopTransaction", {"meterStop":51880,"timestamp":"2024-05-15T14:25:17Z","transactionId":-1,"idTag":"ABCD1234","reason":"Local"}] 2024-05-15_16-29-44-5654_ocpp16-out.txt:[4,"92e07470-12c7-11ef-8013-0c8629738129","PropertyConstraintViolation","",{}]

I have also a wireshark capture.

dallmann-consulting commented 2 months ago

The charger requests to authorize the RFID token and the server says "accepted".

2024-05-15_16-29-31-2338_ocpp16-in.txt:[2, "8afaaa50-12c7-11ef-8012-0c8629738129", "Authorize", {"idTag":"ABCD1234"}] 2024-05-15_16-29-31-2362_ocpp16-out.txt:[3,"8afaaa50-12c7-11ef-8012-0c8629738129",{"idTagInfo":{"expiryDate":"2024-05-15T14:34:31.2351101+00:00","parentIdTag":"charger","status":"Accepted"}}]

Then the charger sends a StartTransaction message:

2024-05-15_16-29-41-5002_ocpp16-in.txt:[2, "9116b0f0-12c7-11ef-8012-0c8629738129", "StartTransaction", {"connectorId":4,"idTag":"ABCD1234","meterStart":51880,"timestamp":"2024-05-15T14:25:12Z"}]

The server responds with status "ConcurrentTx" because there is another transaction running with same RFID token:

2024-05-15_16-29-41-5125_ocpp16-out.txt:[3,"9116b0f0-12c7-11ef-8012-0c8629738129",{"idTagInfo":{"expiryDate":"2199-12-31T00:00:00+01:00","parentIdTag":"charger","status":"ConcurrentTx"},"transactionId":0}]

The OCPP spec says about "ConcurrentTx": ConcurrentTx Identifier is already involved in another transaction and multiple transactions are not allowed.

So the server does not send a transaction ID (=0) and the charger should not start charging. But then the charger surpringly sends a StopTransaction message (with the transaction ID "-1":

2024-05-15_16-29-44-5523_ocpp16-in.txt:[2, "92e07470-12c7-11ef-8013-0c8629738129", "StopTransaction", {"meterStop":51880,"timestamp":"2024-05-15T14:25:17Z","transactionId":-1,"idTag":"ABCD1234","reason":"Local"}]

And the server answers with an error because of the unknown transaction ID.

2024-05-15_16-29-44-5654_ocpp16-out.txt:[4,"92e07470-12c7-11ef-8013-0c8629738129","PropertyConstraintViolation","",{}]

Try to change the configuration in the OCPP server to allow concurrent transactions for the same RFID token: "DenyConcurrentTx": false