lbbrhzn / ocpp

Home Assistant integration for electric vehicle chargers that support the Open Charge Point Protocol (OCPP).
MIT License
199 stars 64 forks source link

Some measurands not working in since 0.5 for WallboxPulsar Plus #1150

Open marcofl opened 2 months ago

marcofl commented 2 months ago

Describe the bug Since 0.5.x I can't get some measurands from my Wallbox Pulsar Plus (Firmware 6.4.41) like Power.Active.Import - it simply stays at 0 during charging.

I'm now back on 0.4.42 and it works again. I can't say whether it happend after the firmware upgrade or after the update from 0.4.x to 0.5.x

To Reproduce Steps to reproduce the behavior:

  1. Wallbox Pulsar Plus with stock firmware or current 6.4.41 connected to Home Assistant 2024.4.4 with OCPP 0.5.x
  2. Power.Active.Import measurand seletcted
  3. start charging
  4. Entity in Home Assistant for Power.Active.Import stays at 0 and never gets updated.
  5. Downgrade to OCPP 0.4.42 and Power.Active.Import works again during charing.

Expected behavior Power.Active.Import gets update during charging

Screenshots log from 0.4.42 during charging:

2024-05-01 11:30:00.661 DEBUG (MainThread) [custom_components.ocpp] Connection latency from 'hass' to 'WallboxPulsar': ping=0.0 ms, pong=3.0 ms
2024-05-01 11:30:01.663 INFO (MainThread) [ocpp] WallboxPulsar: receive message [2,"1433599284","MeterValues",{"meterValue": [{"timestamp": "2024-05-01T09:30:01Z","sampledValue": [{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Power.Active.Import","unit": "W","value": "3283.2"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Power.Offered","unit": "W","value": "9699"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L1","measurand": "Current.Import","unit": "A","value": "14.4"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L2","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L3","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Current.Offered","unit": "A","value": "14"} ]} ],"connectorId": 1,"transactionId": 1714555762}]
2024-05-01 11:30:01.664 DEBUG (MainThread) [custom_components.ocpp] process_phases: metric: Current.Import, phase_info: {'unit': 'A', 'L1': 14.4, 'L2': 0.0, 'L3': 0.0} value: 14.400000 unit :A
2024-05-01 11:30:01.664 INFO (MainThread) [ocpp] WallboxPulsar: send [3,"1433599284",{}]

new wallbox connection with 0.4.42:

2024-05-01 11:24:00.465 INFO (MainThread) [custom_components.ocpp] Websocket Subprotocol matched: ocpp1.6
2024-05-01 11:24:00.465 INFO (MainThread) [custom_components.ocpp] Charger websocket path=/WallboxPulsar
2024-05-01 11:24:00.465 INFO (MainThread) [custom_components.ocpp] Charger WallboxPulsar connected to 0.0.0.0:9000.
2024-05-01 11:24:00.529 INFO (MainThread) [ocpp] WallboxPulsar: receive message [2,"234009003","StatusNotification",{"info": "","vendorId": "com.wallbox","vendorErrorCode": "","connectorId": 0,"errorCode": "NoError","status": "Available","timestamp": "2024-05-01T09:24:00Z"}]
2024-05-01 11:24:00.529 INFO (MainThread) [ocpp] WallboxPulsar: send [3,"234009003",{}]
2024-05-01 11:24:00.538 INFO (MainThread) [ocpp] WallboxPulsar: receive message [2,"2033053440","StatusNotification",{"info": "","vendorId": "com.wallbox","vendorErrorCode": "","connectorId": 1,"errorCode": "NoError","status": "Finishing","timestamp": "2024-05-01T09:24:00Z"}]
2024-05-01 11:24:00.538 INFO (MainThread) [ocpp] WallboxPulsar: send [3,"2033053440",{}]
2024-05-01 11:24:02.466 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"66151bb2-476c-4fd2-8fce-5a8827587282","GetConfiguration",{"key":["SupportedFeatureProfiles"]}]
2024-05-01 11:24:02.538 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"66151bb2-476c-4fd2-8fce-5a8827587282",{"unknownKey": [],"configurationKey": [{"readonly": true,"key": "SupportedFeatureProfiles","value": "Core,FirmwareManagement,LocalAuthListManagement,Reservation,SmartCharging,RemoteTrigger"} ]}]
2024-05-01 11:24:02.538 DEBUG (MainThread) [custom_components.ocpp] Feature profiles returned: Profiles.CORE|FW|SMART|RES|REM|AUTH
2024-05-01 11:24:02.538 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"3d2a6abf-6cf9-47a9-b95e-ecab35ac66d5","GetConfiguration",{"key":["NumberOfConnectors"]}]
2024-05-01 11:24:02.558 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"3d2a6abf-6cf9-47a9-b95e-ecab35ac66d5",{"unknownKey": [],"configurationKey": [{"readonly": true,"key": "NumberOfConnectors","value": "1"} ]}]
2024-05-01 11:24:02.558 DEBUG (MainThread) [custom_components.ocpp] Get Configuration for NumberOfConnectors: 1
2024-05-01 11:24:02.558 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"607fb079-d666-4807-b75c-edff062b4ecd","GetConfiguration",{"key":["HeartbeatInterval"]}]

0.5.2 init on new connection:

2024-05-01 11:35:51.565 INFO (MainThread) [custom_components.ocpp] Websocket Subprotocol matched: ocpp1.6
2024-05-01 11:35:51.566 INFO (MainThread) [custom_components.ocpp] Charger websocket path=/WallboxPulsar
2024-05-01 11:35:51.566 INFO (MainThread) [custom_components.ocpp] Charger WallboxPulsar connected to 0.0.0.0:9000.
2024-05-01 11:35:51.629 INFO (MainThread) [ocpp] WallboxPulsar: receive message [2,"1593445089","StatusNotification",{"info": "","vendorId": "com.wallbox","vendorErrorCode": "","connectorId": 0,"errorCode": "NoError","status": "Available","timestamp": "2024-05-01T09:35:51Z"}]
2024-05-01 11:35:51.629 INFO (MainThread) [ocpp] WallboxPulsar: send [3,"1593445089",{}]
2024-05-01 11:35:51.642 INFO (MainThread) [ocpp] WallboxPulsar: receive message [2,"1462581385","StatusNotification",{"info": "","vendorId": "com.wallbox","vendorErrorCode": "","connectorId": 1,"errorCode": "NoError","status": "Finishing","timestamp": "2024-05-01T09:35:51Z"}]
2024-05-01 11:35:51.642 INFO (MainThread) [ocpp] WallboxPulsar: send [3,"1462581385",{}]
2024-05-01 11:35:53.566 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"151f1182-f947-4ea1-8888-22ce3ae19ef3","GetConfiguration",{"key":["SupportedFeatureProfiles"]}]
2024-05-01 11:35:53.586 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"151f1182-f947-4ea1-8888-22ce3ae19ef3",{"unknownKey": [],"configurationKey": [{"readonly": true,"key": "SupportedFeatureProfiles","value": "Core,FirmwareManagement,LocalAuthListManagement,Reservation,SmartCharging,RemoteTrigger"} ]}]
2024-05-01 11:35:53.586 DEBUG (MainThread) [custom_components.ocpp] Feature profiles returned: Profiles.CORE|FW|SMART|RES|REM|AUTH
2024-05-01 11:35:53.586 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"5e95ef9e-5bbd-44b6-874d-7a150a0b3f33","GetConfiguration",{"key":["NumberOfConnectors"]}]
2024-05-01 11:35:53.606 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"5e95ef9e-5bbd-44b6-874d-7a150a0b3f33",{"unknownKey": [],"configurationKey": [{"readonly": true,"key": "NumberOfConnectors","value": "1"} ]}]
2024-05-01 11:35:53.606 DEBUG (MainThread) [custom_components.ocpp] Get Configuration for NumberOfConnectors: 1
2024-05-01 11:35:53.606 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"795aba9c-42ec-4f07-9296-3a3447f212e5","GetConfiguration",{"key":["HeartbeatInterval"]}]
2024-05-01 11:35:53.622 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"795aba9c-42ec-4f07-9296-3a3447f212e5",{"unknownKey": [],"configurationKey": [{"readonly": false,"key": "HeartbeatInterval","value": "3600"} ]}]
2024-05-01 11:35:53.622 DEBUG (MainThread) [custom_components.ocpp] Get Configuration for HeartbeatInterval: 3600
2024-05-01 11:35:53.623 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' trying measurand 'Power.Active.Import'
2024-05-01 11:35:53.623 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"f07f42e7-af55-43ed-9ce1-d2a7aaa96a15","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Power.Active.Import"}]
2024-05-01 11:35:53.667 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"f07f42e7-af55-43ed-9ce1-d2a7aaa96a15",{"status": "Accepted"}]
2024-05-01 11:35:53.667 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' adding measurand 'Power.Active.Import'
2024-05-01 11:35:53.667 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' trying measurand 'Power.Offered'
2024-05-01 11:35:53.667 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"1dc7af01-2dc1-4979-80cd-e5521f7191b1","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Power.Offered"}]
2024-05-01 11:35:53.722 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"1dc7af01-2dc1-4979-80cd-e5521f7191b1",{"status": "Accepted"}]
2024-05-01 11:35:53.723 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' adding measurand 'Power.Offered'
2024-05-01 11:35:53.723 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' trying measurand 'Current.Import'
2024-05-01 11:35:53.723 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"6f5b9258-113e-4f48-8d2a-439d5e182d6c","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Current.Import"}]
2024-05-01 11:35:53.758 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"6f5b9258-113e-4f48-8d2a-439d5e182d6c",{"status": "Accepted"}]
2024-05-01 11:35:53.758 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' adding measurand 'Current.Import'
2024-05-01 11:35:53.758 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' trying measurand 'Current.Offered'
2024-05-01 11:35:53.758 INFO (MainThread) [ocpp] WallboxPulsar: send [2,"92084588-e1aa-447c-83a1-cd95b8d6e03a","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Current.Offered"}]
2024-05-01 11:35:53.790 INFO (MainThread) [ocpp] WallboxPulsar: receive message [3,"92084588-e1aa-447c-83a1-cd95b8d6e03a",{"status": "Accepted"}]
2024-05-01 11:35:53.790 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' adding measurand 'Current.Offered'
2024-05-01 11:35:53.790 DEBUG (MainThread) [custom_components.ocpp] 'WallboxPulsar' allowed measurands 'Power.Active.Import,Power.Offered,Current.Import,Current.Offered'

Additional context I also tried to switch to all_measurands = MEASURANDS in api.py, but that didn't fix it or gave me more insights in the debug log.

Thanks in advance, and I'm happy to buy you a coffee 🙂

marcofl commented 2 months ago

Update, during reproducing the logs with 0.5.2 it worked again.

TL;DR: I think it is an issue with the configuration assistant that adds all possible monitored values and that might be "too much" for the wallbox pulsar to send, even when tested individually the measurands are accepted. but that's just an educated guess.

logs from 0.5.2 during charging:

2024-05-01 11:39:04.764 INFO (MainThread) [ocpp] WallboxPulsar: receive message [2,"1014383070","MeterValues",{"meterValue": [{"timestamp": "2024-05-01T09:39:04Z","sampledValue": [{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Power.Active.Import","unit": "W","value": "3297.6"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Power.Offered","unit": "W","value": "9699"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L1","measurand": "Current.Import","unit": "A","value": "14.4"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L2","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L3","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Current.Offered","unit": "A","value": "14"} ]} ],"connectorId": 1,"transactionId": 1714556302}]

This time it was no fresh install of 0.5.2 but an update from 0.4.42 without re-adding the integration in hass. maybe there is something wrong with the config? how can I check that?

core.config_entries part after migration from 0.4.42 to 0.5.2:

      {
        "entry_id": "93201235d8ad407b5f9fe734dd74b0fd",
        "version": 1,
        "minor_version": 1,
        "domain": "ocpp",
        "title": "hass",
        "data": {
          "host": "0.0.0.0",
          "port": 9000,
          "ssl": false,
          "ssl_certfile_path": "/config/fullchain.pem",
          "ssl_keyfile_path": "/config/privkey.pem",
          "csid": "hass",
          "cpid": "WallboxPulsar",
          "max_current": 16,
          "meter_interval": 60,
          "idle_interval": 900,
          "websocket_close_timeout": 10,
          "websocket_ping_tries": 2,
          "websocket_ping_interval": 20,
          "websocket_ping_timeout": 20,
          "skip_schema_validation": false,
          "force_smart_charging": false,
          "monitored_variables": "Power.Active.Import,Power.Offered,Current.Import,Current.Offered"
        },

and when I delete and re-add & reconfigure (WebUI) the integration with only the same 4 monitored variables, it lookes like this:

      {
        "entry_id": "79b0dddf5e847ea5277519000d5e370e",
        "version": 1,
        "minor_version": 1,
        "domain": "ocpp",
        "title": "hass",
        "data": {
          "host": "0.0.0.0",
          "port": 9000,
          "ssl": false,
          "ssl_certfile_path": "/config/fullchain.pem",
          "ssl_keyfile_path": "/config/privkey.pem",
          "csid": "hass",
          "cpid": "WallboxPulsar",
          "max_current": 16,
          "monitored_variables": "Current.Export,Current.Import,Current.Offered,Energy.Active.Export.Interval,Energy.Active.Export.Register,Energy.Active.Import.Interval,Energy.Active.Import.Register,Energy.Reactive.Export.Interval,Energy.Reactive.Export.Register,Energy.Reactive.Import.Interval,Energy.Reactive.Import.Register,Frequency,Power.Active.Export,Power.Active.Import,Power.Factor,Power.Offered,Power.Reactive.Export,Power.Reactive.Import,RPM,SoC,Temperature,Voltage",
          "meter_interval": 60,
          "idle_interval": 900,
          "websocket_close_timeout": 10,
          "websocket_ping_tries": 2,
          "websocket_ping_interval": 20,
          "websocket_ping_timeout": 20,
          "skip_schema_validation": false,
          "force_smart_charging": false
        },

and then during charging, it doesn't work anymore:

2024-05-01 11:51:05.886 INFO (MainThread) [ocpp] WallboxPulsar: receive message [2,"478819625","MeterValues",{"meterValue": [{"timestamp": "2024-05-01T09:51:05Z","sampledValue": [{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L1","measurand": "Current.Export","unit": "A","value": "0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L2","measurand": "Current.Export","unit": "A","value": "0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L3","measurand": "Current.Export","unit": "A","value": "0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L1","measurand": "Current.Import","unit": "A","value": "14.4"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L2","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","phase": "L3","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Current.Offered","unit": "A","value": "14"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Energy.Active.Export.Interval","unit": "Wh","value": "0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Energy.Active.Export.Register","unit": "Wh","value": "0"},{"format": "Raw","location": "Outlet","context": "Sample.Periodic","measurand": "Energy.Active.Import.Interval","unit": "Wh","value": "54.2"} ]} ],"connectorId": 1,"transactionId": 1714556988}]

no Power.Active.Import

and then, when I manually change the core.config_entries to:

          "monitored_variables": "Power.Active.Import,Power.Offered,Current.Import,Current.Offered"

it works again with 0.5.2.

lbbrhzn commented 1 month ago

In v0.5.x, the ocpp integration tries try to autodetect the monitored variables by adding them one by one, skipping those that result in an error from the charger. It appears the Wallbox does not send an error, even though it does not support the (large) list of measurands. We should give the user the option to do manual configuration to work around this.

Roarrk commented 3 weeks ago

Changing the monitored_variables and restarting home assistant solved the same issue for me, thanks @marcofl :)

stefan73 commented 3 days ago

Same here for a Entratek Power Dot Fix (which is an IoCharger IOCAH10-22T). With the default behaviour of 0.5x the measurands have reduced to voltage only. I tried all_measurands = MEASURANDS before and it did not fix it.

Used ssh to change /config/.storage/core.config_entries as follows. "monitored_variables": "Current.Import,Current.Offered,Energy.Active.Import.Interval,Energy.Active.Import.Register,Power.Active.Import,Temperature,Voltage,SoC",

Now the measureands work again. Homeassistant reports on restart that a reboot is required. A reboot is required to apply MeterValuesSampledData=Current.Import,Current.Offered,Energy.Active.Import.Interval,Energy.Active.Import.Register,Power.Active.Import,Temperature,Voltage,SoC Booted wallbox and homeassistant multiple times. Message does not vanish. Seems to me another issue with the wallbox firmware, which I can ignore.

P.S.: This fixes https://github.com/lbbrhzn/ocpp/issues/1124