Session time and other measurands are not reported when stop transaction is executed in Etrel Inch

[mazzy89]

Version of the custom_component

v0.5.0

Configuration

Add your logs here.

Describe the bug

I charge my EV that it is set to 80% charging limit. Once it gets to 80% it stops charging. The CS responds that EV stopped charging. The charging session is then paused until I go to my charging station and click stop session. At that point this logic is executed https://github.com/lbbrhzn/ocpp/blob/5ad31b4068d1c31069696ecfaa1c6137945638ec/custom_components/ocpp/api.py#L1381

It is not clear to me why in that logic the session time is not registered. We should also report the session time when the session is stopped.

Debug log

Add your logs here.

[mazzy89]

I've found out that the session time is registered here https://github.com/lbbrhzn/ocpp/blob/5ad31b4068d1c31069696ecfaa1c6137945638ec/custom_components/ocpp/api.py#L1100 when meter values are sent. However I have found out the warning message

2023-12-07 12:00:00.152 WARNING (MainThread) [custom_components.ocpp] Unknown transaction detected with id=-16

and since there is no transaction_matches set to True the session time is never registered.

https://github.com/lbbrhzn/ocpp/blob/5ad31b4068d1c31069696ecfaa1c6137945638ec/custom_components/ocpp/api.py#L1131

The transaction_id is set to -16 while the value in the sensor.charger_transaction_id (which I assume is self.active_transaction_id is 1701939251 which create a mismatch.

[mazzy89]

self.active_transaction_id

is set at the start of the charging with the time in unix format.

but then the transaction ID is retrieved from the context here https://github.com/lbbrhzn/ocpp/blob/5ad31b4068d1c31069696ecfaa1c6137945638ec/custom_components/ocpp/api.py#L1103

so there is a mismatch of the values.

Pinging here @lbbrhzn since you have introduced transaction_id in the unix format in this PR. https://github.com/lbbrhzn/ocpp/pull/437/files

could you explain why you have used unix time?

[mazzy89]

It would be nice to get here an answer so to wire changes to add support for Etrel stations.

[mazzy89]

I've also noticed that when the charging session terminates because the car is charged, differently by the case when the session is stopped manually, no measured is reported. At this stage it makes this integration not suitable for Etrel charging station unless we fix this problem and make happen the transaction matches.

[mazzy89]

I guess the missing logic resides somewhere in between these lines https://github.com/lbbrhzn/ocpp/blob/5ad31b4068d1c31069696ecfaa1c6137945638ec/custom_components/ocpp/api.py#L1117-L1127

I have added some debug output and in the next charge session I'm going to print out values of transaction_id and active_transaction_id

Ideally I would like to wire out a PR to cover these two missing things:

• Add session time in on_stop_transaction function
• Fix logic to match transaction id and allow measured to be reported

I will continue and report updates later once I will have charged the car and get some meaningfull logs

[mazzy89]

I can confirm that no meter values are written because the transaction mismatch.

active_transaction_id is an unix time while my transaction id is a counter of the charging sessions in my station. Then there is always a mismatch and no data is propagate from the station to HA. Not sure though my transaction id is a negative number but i do not think it is a big deal

2023-12-12 11:55:02.776 INFO (MainThread) [ocpp] charger: receive message [2,"af","MeterValues",{"connectorId":1,"meterValue":[{"timestamp":"2023-12-12T10:54:59.669Z","sampledValue":[{"value":"15.44","context":"Sample.Clock","measurand":"Current.Import","phase":"L1","unit":"A"},{"value":"14.944","context":"Sample.Clock","measurand":"Current.Import","phase":"L2","unit":"A"},{"value":"15.2","context":"Sample.Clock","measurand":"Current.Import","phase":"L3","unit":"A"},{"value":"40.290667","context":"Sample.Clock","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"50.01","context":"Sample.Clock","measurand":"Frequency"},{"value":"3.584","context":"Sample.Clock","measurand":"Power.Active.Import","phase":"L1","unit":"kW"},{"value":"3.456","context":"Sample.Clock","measurand":"Power.Active.Import","phase":"L2","unit":"kW"},{"value":"3.504","context":"Sample.Clock","measurand":"Power.Active.Import","phase":"L3","unit":"kW"},{"value":"10.56","context":"Sample.Clock","measurand":"Power.Active.Import","unit":"kW"},{"value":"0.975","context":"Sample.Clock","measurand":"Power.Factor"},{"value":"13","context":"Sample.Clock","measurand":"Temperature","unit":"Celsius"},{"value":"239.06","context":"Sample.Clock","measurand":"Voltage","phase":"L1","unit":"V"},{"value":"236.83","context":"Sample.Clock","measurand":"Voltage","phase":"L2","unit":"V"},{"value":"236.63","context":"Sample.Clock","measurand":"Voltage","phase":"L3","unit":"V"}]}],"transactionId":-27}]

I've looked at the logic and active_transaction_id is used to calculate the session time. So if I set it to my transaction_id it will break the session duration sensor.

I can't change the transaction_id coming from my charging station. then the only way to approach this would be to change it in backend here.

[mazzy89]

In the StartTransaction I do not have any transaction_id so in the function on_start_transaction I cannot pull any other transaction_id to replace the current one with the unix time.

[mazzy89]

I've noticed that the integration sets the transaction id as Unix time and then it sends it to the charging station. Is the charging station supposed to set this transaction id? Does it belong to the OCPP standard? Because in that case, it is an issue with my charging station that does not set tback the transaction id

[lbbrhzn]

accordiing to the OCPP standard the Central System specifies the transaction ID. For this integration we chose to derive the transaction from the unix time, because it guarantees a unique transaction id for every transaction, and allows you to easily derive the session time, even when home assistant is rebooted. If we would use some other scheme, we would need to be able to store the transaction id and the session starting time for each transaction persistently.

[mazzy89]

@lbbrhzn So then at this point is my charging station vendor that is not following the OCPP standard? what do you recommend then? any ideas? I can get back to the vendor and ask for more information. otherwise any other ideas on how to accommodate this use case? I'm keen to hear and have the bandwidth and skills to implement any required changes on this integration.

[lbbrhzn]

This is the OCPP standard:

The transaction ID is generated by the Central System, and reported back by the charger. If your vendor is doing something else, your best option is to ask them to comply to the standard.

[mazzy89]

ok then it's my station and the vendor that does not follow the standard or some issues in their software. I will ask to the vendor.

[lbbrhzn]

If your charger is not compliant, you may be able to work around it (by storing the time of the start transaction locally), but I would urge you to fork the project and do your modifications there. In general we don't include fixes for non-compliant chargers in this repository, because of the risk breaking things for chargers that are fully compliant.

[mazzy89]

Thanks for the recommendation @lbbrhzn and yes it makes perfect sense to not include workarounds here for non-complaint charging stations.

I'm writing to the vendor's support and finding out what they say.

Meanwhile, I might overcome this issue by calculating the session time by looking at the status of the connector. I should be able to do that.

[mazzy89]

For completeness here a full log of the initial exchange of info depicted in the diagram above for my CP

2023-12-12 11:50:09.206 INFO (MainThread) [ocpp] charger: receive message [2,"a8","StatusNotification",{"connectorId":1,"status":"Available","errorCode":"NoError","info":"","timestamp":"2023-12-12T10:50:08.575Z","vendorId":"Etrel","vendorErrorCode":"CablePluggedToVehicle"}]
2023-12-12 11:50:09.208 INFO (MainThread) [ocpp] charger: send [3,"a8",{}]
2023-12-12 11:50:09.255 INFO (MainThread) [ocpp] charger: receive message [2,"a9","StatusNotification",{"connectorId":1,"status":"Preparing","errorCode":"NoError","info":"Usage initiated (plug inserted, user authorised, r","timestamp":"2023-12-12T10:50:08.626Z","vendorId":"Etrel"}]
2023-12-12 11:50:09.256 INFO (MainThread) [ocpp] charger: send [3,"a9",{}]
2023-12-12 11:50:09.503 INFO (MainThread) [ocpp] charger: receive message [2,"aa","StartTransaction",{"connectorId":1,"idTag":"#1111","timestamp":"2023-12-12T10:50:08.83Z","meterStart":39574}]
2023-12-12 11:50:09.510 DEBUG (MainThread) [custom_components.ocpp] id_tag='#1111' not found in auth_list, default authorization_status='Accepted'
2023-12-12 11:50:09.514 INFO (MainThread) [ocpp] charger: send [3,"aa",{"transactionId":1702378209,"idTagInfo":{"status":"Accepted"}}]
2023-12-12 11:50:10.110 INFO (MainThread) [ocpp] charger: receive message [2,"ab","StatusNotification",{"connectorId":1,"status":"Charging","errorCode":"NoError","info":"Charging session started or resumed.","timestamp":"2023-12-12T10:50:09.169Z","vendorId":"Etrel"}]
2023-12-12 11:50:10.111 INFO (MainThread) [ocpp] charger: send [3,"ab",{}]
2023-12-12 11:50:10.223 INFO (MainThread) [ocpp] charger: receive message [2,"ac","DataTransfer",{"vendorId":"Etrel","messageId":"ChargingModeChanged","data":"{\n \"connectorId\": 1,\n \"transactionId\": 27,\n \"chargingMode\": \"Fast\",\n \"departureTime\": null,\n \"timestamp\": \"2023-12-12T10:50:09.2387848Z\"\n}"}]
2023-12-12 11:50:10.241 DEBUG (MainThread) [custom_components.ocpp] Data transfer received from charger: {'message_id': 'ChargingModeChanged', 'data': '{\n "connectorId": 1,\n "transactionId": 27,\n "chargingMode": "Fast",\n "departureTime": null,\n "timestamp": "2023-12-12T10:50:09.2387848Z"\n}'}
2023-12-12 11:50:10.247 INFO (MainThread) [ocpp] charger: send [3,"ac",{"status":"Accepted"}]
2023-12-12 11:50:10.258 INFO (MainThread) [ocpp] charger: receive message [2,"ad","StatusNotification",{"connectorId":1,"status":"Charging","errorCode":"NoError","info":"DepartureTime: 2023-12-12T12:30:00","timestamp":"2023-12-12T10:50:09.297Z","vendorId":"Etrel","vendorErrorCode":"UserHasConfirmedProposedDepartureTime"}]
2023-12-12 11:50:10.260 INFO (MainThread) [ocpp] charger: send [3,"ad",{}]
2023-12-12 11:50:12.083 INFO (MainThread) [ocpp] charger: receive message [2,"ae","StatusNotification",{"connectorId":1,"status":"Charging","errorCode":"NoError","info":"DC leakage test succeeded. Connector id: 1","timestamp":"2023-12-12T10:50:11.453Z","vendorId":"Etrel","vendorErrorCode":"BenderTestSucceeded"}]
2023-12-12 11:50:12.086 INFO (MainThread) [ocpp] charger: send [3,"ae",{}]

And it is visible that the CS sends transaction id in unix time but the CP responds with its own transaction id.

[mazzy89]

It seems that the Etrel charging station sets the transaction ID when the authorization is done remotely. When it is done locally then it uses the internal ID which the vendor sets as a negative number to recognize the local authorization.

So I think the problem is somehow here

2023-12-12 11:50:09.510 DEBUG (MainThread) [custom_components.ocpp] id_tag='#1111' not found in auth_list, default authorization_status='Accepted'

the id_tag is not found in the authorization_list. How can I set up the authorization list?

[mazzy89]

I think I have found an example that I can set it up https://github.com/lbbrhzn/ocpp/blob/5ad31b4068d1c31069696ecfaa1c6137945638ec/config/configuration.yaml#L49

[lbbrhzn]

That's correct. Please note that I am working on configuration of tags through config / option flows instead of yaml.

[mazzy89]

@lbbrhzn it is not merged yet though. I will follow the release and then I will move the configuration once the new release is wired.

[lbbrhzn]

According to the OCPP standard, local authorization may be done when the connection to the central server is offline.

When connection to the Central Server is restored, the Charge Point SHALL send a Start Transaction request for any transaction that was authorized offline, as required by transaction-related message handling.

[mazzy89]

According to the OCPP standard, local authorization may be done when the connection to the central server is offline.

Correct and it is not my case. My station is always connected to the CS.

I think my issue is it is not related to that either.

Even if the ID tag is not in the list, the default authorization is set to Accepted. Then in my case, I should not encounter any issues in setting the transaction_id.

I have set the auth_list. Let's see what is going to happen in the next charging session.

[mazzy89]

The vendor replied

If your charger is still sending negative transaction IDs, is most likely down to the type of charging authorization you are using.

So they claim that it is complaint and the backend once sent the transaction id, the charge point should set the transaction id correctly.

I will retry again today now that I've set auth_list and see what I will get it.

[mazzy89]

This time the id tag has been found in the list but the OCPP ID still remains the local one.

Here are some logs of the initial info exchange.

2023-12-13 15:20:28.518 INFO (MainThread) [ocpp] charger: receive message [2,"2f","StatusNotification",{"connectorId":1,"status":"Available","errorCode":"NoError","info":"","timestamp":"2023-12-13T14:20:28.411Z","vendorId":"Etrel","vendorErrorCode":"CablePluggedToVehicle"}]
2023-12-13 15:20:28.521 INFO (MainThread) [ocpp] charger: send [3,"2f",{}]
2023-12-13 15:20:44.504 DEBUG (MainThread) [custom_components.ocpp] Connection latency from 'central' to 'charger': ping=1.0 ms, pong=2.0 ms
2023-12-13 15:21:02.250 INFO (MainThread) [ocpp] charger: receive message [2,"30","StatusNotification",{"connectorId":1,"status":"Preparing","errorCode":"NoError","info":"Usage initiated (plug inserted, user authorised, r","timestamp":"2023-12-13T14:21:02.09Z","vendorId":"Etrel"}]
2023-12-13 15:21:02.252 INFO (MainThread) [ocpp] charger: send [3,"30",{}]
2023-12-13 15:21:02.517 INFO (MainThread) [ocpp] charger: receive message [2,"31","StartTransaction",{"connectorId":1,"idTag":"#1111","timestamp":"2023-12-13T14:21:02.344Z","meterStart":49442}]
2023-12-13 15:21:02.522 DEBUG (MainThread) [custom_components.ocpp] id_tag='#1111' found in auth_list, authorization_status='Accepted'
2023-12-13 15:21:02.525 INFO (MainThread) [ocpp] charger: send [3,"31",{"transactionId":1702477262,"idTagInfo":{"status":"Accepted"}}]
2023-12-13 15:21:02.910 INFO (MainThread) [ocpp] charger: receive message [2,"32","StatusNotification",{"connectorId":1,"status":"Charging","errorCode":"NoError","info":"Charging session started or resumed.","timestamp":"2023-12-13T14:21:02.671Z","vendorId":"Etrel"}]
2023-12-13 15:21:02.912 INFO (MainThread) [ocpp] charger: send [3,"32",{}]
2023-12-13 15:21:02.963 INFO (MainThread) [ocpp] charger: receive message [2,"33","DataTransfer",{"vendorId":"Etrel","messageId":"ChargingModeChanged","data":"{\n \"connectorId\": 1,\n \"transactionId\": 28,\n \"chargingMode\": \"Fast\",\n \"departureTime\": null,\n \"timestamp\": \"2023-12-13T14:21:02.7958145Z\"\n}"}]
2023-12-13 15:21:02.973 DEBUG (MainThread) [custom_components.ocpp] Data transfer received from charger: {'message_id': 'ChargingModeChanged', 'data': '{\n "connectorId": 1,\n "transactionId": 28,\n "chargingMode": "Fast",\n "departureTime": null,\n "timestamp": "2023-12-13T14:21:02.7958145Z"\n}'}
2023-12-13 15:21:02.979 INFO (MainThread) [ocpp] charger: send [3,"33",{"status":"Accepted"}]
2023-12-13 15:21:03.024 INFO (MainThread) [ocpp] charger: receive message [2,"34","StatusNotification",{"connectorId":1,"status":"Charging","errorCode":"NoError","info":"DepartureTime: 2023-12-13T16:00:00","timestamp":"2023-12-13T14:21:02.852Z","vendorId":"Etrel","vendorErrorCode":"UserHasConfirmedProposedDepartureTime"}]
2023-12-13 15:21:03.026 INFO (MainThread) [ocpp] charger: send [3,"34",{}]
2023-12-13 15:21:04.508 DEBUG (MainThread) [custom_components.ocpp] Connection latency from 'central' to 'charger': ping=1.0 ms, pong=2.0 ms
2023-12-13 15:21:05.166 INFO (MainThread) [ocpp] charger: receive message [2,"35","StatusNotification",{"connectorId":1,"status":"Charging","errorCode":"NoError","info":"DC leakage test succeeded. Connector id: 1","timestamp":"2023-12-13T14:21:05.056Z","vendorId":"Etrel","vendorErrorCode":"BenderTestSucceeded"}]
2023-12-13 15:21:05.169 INFO (MainThread) [ocpp] charger: send [3,"35",{}]

At this point I'm not sure where is the issue. Whether on the vendor side or on this integration.

Here the OCPP ID in the GUI of the CP

[mazzy89]

And now works

It was an issue on my CP. Once i've enabled a (hidden) settings to allow authorization with the CS everything started to work.

[mazzy89]

@lbbrhzn should I need to wire a PR to add that Etrel stations are supported?

[lbbrhzn]

Please do!

[mazzy89]

Also, the question remains still valid: can we add session time during the stop of a transaction? why is it not there?

[mazzy89]

PR wired https://github.com/lbbrhzn/ocpp/pull/1011

[github-actions[bot]]

Stale issue message