Vestel EVC04 - Reconnect every 25s

pvillmann commented 1 month ago

Hi, i have connected my Vestel EVC04 with Firmware v3.166.0 (newest) via OCPP to the custom Integration in HomeAssistant (https://github.com/lbbrhzn/ocpp). Vestel configuration and Config of Integration in HA is completly default.

My Problem is, the connection drops every 25s and all entity are set to "not available". After additional 25s the connection is established again. (Reconnect counter increase every time by 1)

To Reproduce Steps to reproduce the behavior: Install OCPP integration in default way Active OCPP on Vestel WebUI and set server to ws://ha-ip:9000/ Save

The Homeassistant Logs in debug mode shows:

in Vestel Log i the only: 13.09.2024-11:32:41 [INFO] CLIENT: Client RX: [4,"7cfd7ec2-6340-4994-b797-bf5f9851b5d2","InternalError","An unexpected error occurred.",{}]13.09.2024-11:32:41 [INFO] response waiting :1...

Notifications from HomeAssistant:

Reference:

https://github.com/lbbrhzn/ocpp/issues/1323

go2sh commented 1 month ago

I have the same problem with a warp2 charger. It needs to reconnect constantly. Once every minute or ao

stefa168 commented 1 month ago

Same issue for me with a SCAME charger (ocpp j1.6)

jainmohit2001 commented 4 weeks ago

Hi @pvillmann , please share the DEBUG logs for the OCPP package. See https://github.com/mobilityhouse/ocpp?tab=readme-ov-file#debugging for more information about debugging.

pvillmann commented 4 weeks ago

Hi,

it's not so easy to do this in homeassistant :(

the only thing i found is:

`Logger: ocpp Quelle: /usr/local/lib/python3.12/site-packages/ocpp/charge_point.py:314 Erstmals aufgetreten: 15:50:29 (3 Vorkommnisse) Zuletzt protokolliert: 15:52:12

Error while handling request '<Call - unique_id=d4091b09-7377-4d7e-ba2c-758dc62b7c99, action=MeterValues, payload={'connectorId': 1, 'transactionId': 1726213848, 'meterValue': [{'timestamp': '2024-09-13T09:43:59Z', 'sampledValue': [{'measurand': 'Energy.Active.Import.Register', 'unit': 'Wh', 'value': '6618', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Offered', 'unit': 'A', 'value': '', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Offered', 'unit': 'W', 'value': '11040', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L1', 'value': '222', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L2', 'value': '230', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L3', 'value': '230', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L1', 'value': '16.1', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L2', 'value': '0.0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L3', 'value': '0.0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L1', 'value': '3549', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L2', 'value': '0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L3', 'value': '0', 'context': 'Sample.Periodic', 'location': 'Outlet'}]}]}>'
Error while handling request '<Call - unique_id=e4b3b0c8-5e21-4aa4-8c92-d043658653d7, action=MeterValues, payload={'connectorId': 1, 'transactionId': 1726213848, 'meterValue': [{'timestamp': '2024-09-13T09:44:59Z', 'sampledValue': [{'measurand': 'Energy.Active.Import.Register', 'unit': 'Wh', 'value': '6676', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Offered', 'unit': 'A', 'value': '', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Offered', 'unit': 'W', 'value': '11040', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L1', 'value': '223', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L2', 'value': '227', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L3', 'value': '235', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L1', 'value': '16.1', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L2', 'value': '0.0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L3', 'value': '0.0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L1', 'value': '3568', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L2', 'value': '0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L3', 'value': '0', 'context': 'Sample.Periodic', 'location': 'Outlet'}]}]}>'
Error while handling request '<Call - unique_id=21c2e0cc-6510-4217-b712-4336e7d4f730, action=MeterValues, payload={'connectorId': 1, 'transactionId': 1726213848, 'meterValue': [{'timestamp': '2024-09-13T09:45:59Z', 'sampledValue': [{'measurand': 'Energy.Active.Import.Register', 'unit': 'Wh', 'value': '6735', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Offered', 'unit': 'A', 'value': '', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Offered', 'unit': 'W', 'value': '11040', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L1', 'value': '224', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L2', 'value': '230', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Voltage', 'unit': 'V', 'phase': 'L3', 'value': '234', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L1', 'value': '16.0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L2', 'value': '0.0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Current.Import', 'unit': 'A', 'phase': 'L3', 'value': '0.0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L1', 'value': '3570', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L2', 'value': '0', 'context': 'Sample.Periodic', 'location': 'Outlet'}, {'measurand': 'Power.Active.Import', 'unit': 'W', 'phase': 'L3', 'value': '0', 'context': 'Sample.Periodic', 'location': 'Outlet'}]}]}>'
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/ocpp/charge_point.py", line 310, in _handle_call
    response = handler(**snake_case_payload)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/ocpp/routing.py", line 48, in inner
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/ocpp/api.py", line 1271, in on_meter_values
    self._metrics[measurand].value = float(value)
                                     ^^^^^^^^^^^^
ValueError: could not convert string to float: ''`

and

`Dieser Fehler wurde von einer benutzerdefinierten Integration verursacht

Logger: homeassistant Quelle: custom_components/ocpp/api.py:490 Integration: Open Charge Point Protocol (OCPP) (Dokumentation, Probleme) Erstmals aufgetreten: 15:51:20 (1 Vorkommnisse) Zuletzt protokolliert: 15:51:20

Error doing job: Task exception was never retrieved (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/tasks.py", line 520, in wait_for
    return await fut
           ^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/queues.py", line 158, in get
    await getter
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/ocpp/charge_point.py", line 406, in call
    response = await self._get_specific_response(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/ocpp/api.py", line 974, in _get_specific_response
    resp = await super()._get_specific_response(unique_id, timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/ocpp/charge_point.py", line 440, in _get_specific_response
    response = await asyncio.wait_for(self._response_queue.get(), timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/tasks.py", line 519, in wait_for
    async with timeouts.timeout(timeout):
  File "/usr/local/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/config/custom_components/ocpp/api.py", line 490, in post_connect
    resp = await self.call(req)
           ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/ocpp/charge_point.py", line 410, in call
    raise asyncio.TimeoutError(
TimeoutError: Waited 30s for response on [2,"f736e2f0-997c-433c-a0ef-a35044bd69d6","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Power.Active.Import"}].`

jainmohit2001 commented 4 weeks ago

The error is pretty obvious here.

self._metrics[measurand].value = float(value)
                                     ^^^^^^^^^^^^
ValueError: could not convert string to float: ''`

{
  "connectorId": 1,
  "transactionId": 1726213848,
  "meterValue": [
    {
      "timestamp": "2024-09-13T09:43:59Z",
      "sampledValue": [
        {
          "measurand": "Energy.Active.Import.Register",
          "unit": "Wh",
          "value": "6618",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Current.Offered",
          "unit": "A",
          "value": "", <--- This is causing the issue
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Power.Offered",
          "unit": "W",
          "value": "11040",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Voltage",
          "unit": "V",
          "phase": "L1",
          "value": "222",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Voltage",
          "unit": "V",
          "phase": "L2",
          "value": "230",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Voltage",
          "unit": "V",
          "phase": "L3",
          "value": "230",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Current.Import",
          "unit": "A",
          "phase": "L1",
          "value": "16.1",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Current.Import",
          "unit": "A",
          "phase": "L2",
          "value": "0.0",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Current.Import",
          "unit": "A",
          "phase": "L3",
          "value": "0.0",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Power.Active.Import",
          "unit": "W",
          "phase": "L1",
          "value": "3549",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Power.Active.Import",
          "unit": "W",
          "phase": "L2",
          "value": "0",
          "context": "Sample.Periodic",
          "location": "Outlet"
        },
        {
          "measurand": "Power.Active.Import",
          "unit": "W",
          "phase": "L3",
          "value": "0",
          "context": "Sample.Periodic",
          "location": "Outlet"
        }
      ]
    }
  ]
}

You need to add some checks before calling float(value)

pvillmann commented 4 weeks ago

Which means the problem has to be solved in "lbbrhzn/ocpp" or is it a problem on Wallbox side?

jainmohit2001 commented 4 weeks ago

This is server side, so in "lbbrhzn/ocpp".

jainmohit2001 commented 3 weeks ago

Closing the issue. It seems like you have found the solution.

mobilityhouse / ocpp

Vestel EVC04 - Reconnect every 25s #661