Pulsar Plus: `SetChargingProfile` gets rejected [FW 5.17.87]

dscho commented 2 months ago

Describe the bug

EVCC was working correctly before I upgraded from v0.128.4 to v0.130.1. After upgrading, SetChargingProfile always gets rejected.

Steps to reproduce

Connect car to a Pulsar Plus charger
observe the log (and the errors in the UI)

Configuration details

log: debug
levels:
  cache: error
  ocpp: trace

meters:
- type: template
  template: senec-home
  usage: grid
  schema: https
  host: 192.168.178.84
  name: grid1
- type: template
  template: senec-home
  usage: pv
  schema: https
  host: 192.168.178.84
  name: bsh
- type: template
  template: senec-home
  usage: battery
  schema: https
  host: 192.168.178.84
  name: senec

chargers:
- type: template
  template: pulsarplus
  name: pulsar

vehicles:
- type: template
  name: id3
  title: id.3
  template: id
  [... login data ...]

loadpoints:
- title: Garage
  charger: pulsar
  mode: pv
  phases: 3
  mincurrent: 6
  maxcurrent: 16

site:
  title: [... title ...]
  meters:
    grid: grid1
    pv:
    - bsh
    battery:
    - senec
  residualPower: 300
  maxGridSupplyWhileBatteryCharging: 50

Log details

Successful SetChargingProfile before update

``` [...] Aug 19 12:06:52 raspberrypi evcc[528]: [site ] DEBUG 2024/08/19 12:06:52 ---- Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 charge power: 4191W Aug 19 12:06:52 raspberrypi evcc[528]: [site ] DEBUG 2024/08/19 12:06:52 pv power: 4842W Aug 19 12:06:52 raspberrypi evcc[528]: [site ] DEBUG 2024/08/19 12:06:52 battery soc: 49% Aug 19 12:06:52 raspberrypi evcc[528]: [site ] DEBUG 2024/08/19 12:06:52 battery power: -93W Aug 19 12:06:52 raspberrypi evcc[528]: [site ] DEBUG 2024/08/19 12:06:52 grid meter: -139W Aug 19 12:06:52 raspberrypi evcc[528]: [site ] DEBUG 2024/08/19 12:06:52 site power: 68W Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 !! session: chargeRater.chargedEnergy=4.1 - chargedAtStartup=0.0 Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 charger status: C Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 soc estimated: 78.28% (vehicle: 77.00%) Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 vehicle soc: 78% Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 vehicle soc limit: 80% Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 vehicle range: 323km Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 pv charge current: min 6A > 5.97A (68W @ 3p, battery: false) Aug 19 12:06:52 raspberrypi evcc[528]: [ocpp ] TRACE 2024/08/19 12:06:52 send evcc: [2,"316577498","SetChargingProfile",{"connectorId":1,"csChargingProfiles":{"chargingProfileId":1,"transactionId":2,"stackLevel":0,"chargingProfilePurpose":"TxProfile","chargingProfileKind":"Relative","chargingSchedule":{"chargingRateUnit":"A","chargingSchedulePeriod":[{"startPeriod":0,"limit":6}]}}}] Aug 19 12:06:52 raspberrypi evcc[528]: [ocpp ] TRACE 2024/08/19 12:06:52 recv evcc: [3,"316577498",{"status": "Accepted"}] Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 max charge current: 6A Aug 19 12:06:52 raspberrypi evcc[528]: [lp-1 ] DEBUG 2024/08/19 12:06:52 !! active phases: 3p = min(0p measured 0p vehicle 3p physical 0p charger) Aug 19 12:07:22 raspberrypi evcc[528]: [site ] DEBUG 2024/08/19 12:07:22 ---- [...] ```

Restart after update

``` [...] Aug 20 11:59:59 raspberrypi systemd[1]: Stopping evcc... Aug 20 11:59:59 raspberrypi systemd[1]: evcc.service: Succeeded. Aug 20 11:59:59 raspberrypi systemd[1]: Stopped evcc. Aug 20 11:59:59 raspberrypi systemd[1]: evcc.service: Consumed 2h 18min 32.572s CPU time. Aug 20 12:00:35 raspberrypi systemd[1]: Started evcc. Aug 20 12:00:35 raspberrypi evcc[637]: [main ] INFO 2024/08/20 12:00:35 evcc 0.130.1 Aug 20 12:00:35 raspberrypi evcc[637]: [main ] INFO 2024/08/20 12:00:35 using config file: /etc/evcc.yaml Aug 20 12:00:35 raspberrypi evcc[637]: [db ] INFO 2024/08/20 12:00:35 using sqlite database: /var/lib/evcc/evcc.db Aug 20 12:00:35 raspberrypi evcc[637]: [main ] INFO 2024/08/20 12:00:35 listening at :7070 Aug 20 12:00:35 raspberrypi evcc[637]: [ocpp-1] DEBUG 2024/08/20 12:00:35 waiting for chargepoint: 5m0s Aug 20 12:00:56 raspberrypi evcc[637]: [ocpp ] INFO 2024/08/20 12:00:56 charge point connected, registering: evcc Aug 20 12:00:56 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:00:56 recv evcc: [2,"1299419085","StatusNotification",{"info": "","vendorId": "com.wallbox","vendorErrorCode": "","connectorId": 0,"errorCode": "NoError","status": "Available","timestamp": "2024-08-20T11:00:55Z"}] Aug 20 12:00:56 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:00:56 send evcc: [3,"1299419085",{}] Aug 20 12:00:56 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:00:56 recv evcc: [2,"1732414336","StatusNotification",{"info": "","vendorId": "com.wallbox","vendorErrorCode": "","connectorId": 1,"errorCode": "NoError","status": "Preparing","timestamp": "2024-08-20T11:00:55Z"}] Aug 20 12:00:56 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:00:56 send evcc: [3,"1732414336",{}] Aug 20 12:00:57 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:00:57 send evcc: [2,"1337973214","GetConfiguration",{}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"1337973214",{"unknownKey": [],"configurationKey": [{"readonly": false,"key": "AllowOfflineTxForUnknownId","value": "true"},{"readonly": false,"key": "AuthorizationCacheEnabled","value": "true"},{"readonly": false,"key": "AuthorizeRemoteTxRequests","value": "false"},{"readonly": false,"key": "BlinkRepeat","value": "10"},{"readonly": false,"key": "ClockAlignedDataInterval","value": "0"},{"readonly": false,"key": "ConnectionTimeOut","value": "120"},{"readonly": false,"key": "ConnectorPhaseRotation","value": "1.Unknown"},{"readonly": true,"key": "ConnectorPhaseRotationMaxLength","value": "1"},{"readonly": true,"key": "GetConfigurationMaxKeys","value": "50"},{"readonly": false,"key": "HeartbeatInterval","value": "60"},{"readonly": false,"key": "LightIntensity","value": "100"},{"readonly": false,"key": "LocalAuthorizeOffline","value": "true"},{"readonly": false,"key": "LocalPreAuthorize","value": "true"},{"readonly": false,"key": "MaxEnergyOnInvalidId","value": "5000"},{"readonly": false,"key": "MeterValuesAlignedData","value": "Energy.Active.Import.Register"},{"readonly": true,"key": "MeterValuesAlignedDataMaxLength","value": "10"},{"readonly": false,"key": "MeterValuesSampledData","value": "Energy.Active.Import.Register"},{"readonly": true,"key": "MeterValuesSampledDataMaxLength","value": "10"},{"readonly": false,"key": "MeterValueSampleInterval","value": "300"},{"readonly": false,"key": "MinimumStatusDuration","value": "1"},{"readonly": true,"key": "NumberOfConnectors","value": "1"},{"readonly": false,"key": "ResetRetries","value": "0"},{"readonly": false,"key": "StopTransactionOnEVSideDisconnect","value": "true"},{"readonly": false,"key": "StopTransactionOnInvalidId","value": "true"},{"readonly": false,"key": "StopTxnAlignedData","value": ""},{"readonly": true,"key": "StopTxnAlignedDataMaxLength","value": "0"},{"readonly": false,"key": "StopTxnSampledData","value": ""},{"readonly": true,"key": "StopTxnSampledDataMaxLength","value": "0"},{"readonly": true,"key": "SupportedFileTransferProtocols","value": ""},{"readonly": true,"key": "SupportedFeatureProfiles","value": "Core,FirmwareManagement,LocalAuthListManagement,Reservation,SmartCharging,RemoteTrigger"},{"readonly": true,"key": "SupportedFeatureProfilesMaxLength","value": "6"},{"readonly": false,"key": "TransactionMessageAttempts","value": "3"},{"readonly": false,"key": "TransactionMessageRetryInterval","value": "60"},{"readonly": false,"key": "UnlockConnectorOnEVSideDisconnect","value": "true"},{"readonly": false,"key": "WebSocketPingInterval","value": "50"},{"readonly": false,"key": "LocalAuthListEnabled","value": "true"},{"readonly": true,"key": "LocalAuthListMaxLength","value": "5000000"},{"readonly": true,"key": "SendLocalListMaxLength","value": "450"},{"readonly": true,"key": "ReserveConnectorZeroSupported","value": "false"},{"readonly": true,"key": "ChargeProfileMaxStackLevel","value": "1"},{"readonly": true,"key": "ChargingScheduleAllowedChargingRateUnit","value": "Current"},{"readonly": true,"key": "ChargingScheduleMaxPeriods","value": "100"},{"readonly": true,"key": "ConnectorSwitch3to1PhaseSupported","value": "false"},{"readonly": true,"key": "MaxChargingProfilesInstalled","value": "1"},{"readonly": false,"key": "WebSocketUrl","value": "ws://192.168.178.86:8887/evcc"},{"readonly": false,"key": "chargingALimitConn1","value": "16"},{"readonly": false,"key": "AuthEnabled","value": "true"},{"readonly": false,"key": "AuthEnabledOffline","value": "true"},{"readonly": false,"key": "AuthDisabledIdTag","value": "NoAuthorization"},{"readonly": false,"key": "minSoC","value": "9"},{"readonly": false,"key": "maxSoC","value": "97"},{"readonly": true,"key": "SSID","value": "VerticalInfinity"},{"readonly": true,"key": "WiFiSignalStrength","value": "64"},{"readonly": true,"key": "SerialNumber","value": "[number]"},{"readonly": true,"key": "PUK","value": "[number]"},{"readonly": true,"key": "WebSocketUrl","value": "ws://192.168.178.86:8887"},{"readonly": true,"key": "WebSocketUser","value": "evcc"},{"readonly": true,"key": "WebSocketPassword","value": ""} ]}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"3528416686","TriggerMessage",{"requestedMessage":"BootNotification"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"3528416686",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [2,"1027082133","BootNotification",{"chargePointSerialNumber": "121196","chargePointVendor": "Wall Box Chargers","meterType": "Internal NON compliant","meterSerialNumber": "","chargePointModel": "PLP1-M-2-4","iccid": "","chargeBoxSerialNumber": "121196","firmwareVersion": "5.17.87","imsi": ""}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [3,"1027082133",{"currentTime":"2024-08-20T11:01:01Z","interval":60,"status":"Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"1795859669","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Power.Active.Import"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"1795859669",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"2123168264","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Energy.Active.Import.Register"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"2123168264",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"1337052265","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"SoC"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"1337052265",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"2128483411","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Current.Offered"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"2128483411",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"1414498378","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Power.Offered"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"1414498378",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"3531551551","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Current.Import"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"3531551551",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"968119474","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Voltage"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"968119474",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"2952143827","ChangeConfiguration",{"key":"MeterValuesSampledData","value":"Power.Active.Import,Energy.Active.Import.Register,SoC,Current.Offered,Power.Offered,Current.Import,Voltage"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"2952143827",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"744373274","TriggerMessage",{"requestedMessage":"MeterValues","connectorId":1}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"744373274",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [2,"1742209402","MeterValues",{"meterValue": [{"timestamp": "2024-08-20T11:01:01Z","sampledValue": [{"format": "Raw","location": "Outlet","context": "Trigger","measurand": "Power.Active.Import","unit": "W","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Trigger","measurand": "Energy.Active.Import.Register","unit": "Wh","value": "4882904.0"},{"format": "Raw","location": "Outlet","context": "Trigger","measurand": "Current.Offered","unit": "A","value": "16"},{"format": "Raw","location": "Outlet","context": "Trigger","measurand": "Power.Offered","unit": "W","value": "11085"},{"format": "Raw","location": "Outlet","context": "Trigger","phase": "L1","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Trigger","phase": "L2","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Trigger","phase": "L3","measurand": "Current.Import","unit": "A","value": "0.0"},{"format": "Raw","location": "Outlet","context": "Trigger","phase": "L1-N","measurand": "Voltage","unit": "V","value": "237.0"},{"format": "Raw","location": "Outlet","context": "Trigger","phase": "L2-N","measurand": "Voltage","unit": "V","value": "230.0"} ]} ],"connectorId": 1}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [3,"1742209402",{}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"2636720771","ChangeConfiguration",{"key":"MeterValueSampleInterval","value":"10"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"2636720771",{"status": "Accepted"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 send evcc: [2,"3173741355","ChangeConfiguration",{"key":"WebSocketPingInterval","value":"30"}] Aug 20 12:01:01 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:01 recv evcc: [3,"3173741355",{"status": "Accepted"}] Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] WARN 2024/08/20 12:01:05 deprecated: mincurrent setting is ignored, please remove Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] WARN 2024/08/20 12:01:05 deprecated: maxcurrent setting is ignored, please remove Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] WARN 2024/08/20 12:01:05 deprecated: phases setting is ignored, please remove Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:05 charge total import: 4882.904kWh Aug 20 12:01:05 raspberrypi evcc[637]: [site ] INFO 2024/08/20 12:01:05 site config: Aug 20 12:01:05 raspberrypi evcc[637]: [site ] INFO 2024/08/20 12:01:05 meters: grid ✓ pv ✓ battery ✓ Aug 20 12:01:05 raspberrypi evcc[637]: [site ] INFO 2024/08/20 12:01:05 grid: power ✓ energy ✗ currents ✗ Aug 20 12:01:05 raspberrypi evcc[637]: [site ] INFO 2024/08/20 12:01:05 pv 1: power ✓ energy ✗ currents ✗ Aug 20 12:01:05 raspberrypi evcc[637]: [site ] INFO 2024/08/20 12:01:05 battery 1: power ✓ energy ✗ currents ✗ soc ✓ capacity ✗ Aug 20 12:01:05 raspberrypi evcc[637]: [site ] INFO 2024/08/20 12:01:05 vehicles: Aug 20 12:01:05 raspberrypi evcc[637]: [site ] INFO 2024/08/20 12:01:05 vehicle 1: range ✓ finish ✓ status ✓ climate ✓ wakeup ✓ Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] INFO 2024/08/20 12:01:05 loadpoint 1: Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] INFO 2024/08/20 12:01:05 mode: pv Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] INFO 2024/08/20 12:01:05 charger: power ✓ energy ✓ currents ✓ phases ✗ wakeup ✗ Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] INFO 2024/08/20 12:01:05 meters: charge ✓ Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] INFO 2024/08/20 12:01:05 charge: power ✓ energy ✓ currents ✓ Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:05 phase timer inactive Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:05 pv timer inactive [...] ```

SetChargingProfile is getting rejected/waiting for local authentication (outdated)

``` [...] Aug 20 12:01:05 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:05 send evcc: [2,"557882437","SetChargingProfile",{"connectorId":1,"csChargingProfiles":{"chargingProfileId":1,"stackLevel":1,"chargingProfilePurpose":"TxDefaultProfile","chargingProfileKind":"Absolute","chargingSchedule":{"startSchedule":"2024-08-20T11:01:05Z","chargingRateUnit":"A","chargingSchedulePeriod":[{"startPeriod":0,"limit":6}]}}}] Aug 20 12:01:05 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:05 recv evcc: [3,"557882437",{"status": "Rejected"}] Aug 20 12:01:05 raspberrypi evcc[637]: [site ] DEBUG 2024/08/20 12:01:05 ---- Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:05 charge power: 0W Aug 20 12:01:05 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:05 charge currents: [0 0 0]A Aug 20 12:01:06 raspberrypi evcc[637]: [site ] DEBUG 2024/08/20 12:01:06 pv power: 4691W Aug 20 12:01:06 raspberrypi evcc[637]: [site ] DEBUG 2024/08/20 12:01:06 battery soc: 50% Aug 20 12:01:06 raspberrypi evcc[637]: [site ] DEBUG 2024/08/20 12:01:06 battery power: -1W Aug 20 12:01:07 raspberrypi evcc[637]: [site ] DEBUG 2024/08/20 12:01:07 grid meter: -4167W Aug 20 12:01:07 raspberrypi evcc[637]: [site ] DEBUG 2024/08/20 12:01:07 site power: -3868W Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] ERROR 2024/08/20 12:01:07 charge meter: not available Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:07 charge total import: 4882.904kWh Aug 20 12:01:07 raspberrypi evcc[637]: [ocpp-1] WARN 2024/08/20 12:01:07 waiting for local authentication Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:07 charger status: B Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:07 charge start energy: 4.88e+03kWh Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] INFO 2024/08/20 12:01:07 car connected Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:07 vehicle api refresh Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:07 pv timer elapse Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:07 pv timer inactive Aug 20 12:01:07 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:07 charge total import: 4882.904kWh Aug 20 12:01:12 raspberrypi evcc[637]: [main ] DEBUG 2024/08/20 12:01:12 vehicle status: B (id.3) Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] INFO 2024/08/20 12:01:12 vehicle updated: unknown -> id.3 Aug 20 12:01:12 raspberrypi evcc[637]: [ocpp-1] WARN 2024/08/20 12:01:12 waiting for local authentication Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:12 vehicle status: B Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:12 vehicle soc: 79% Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:12 vehicle soc limit: 80% Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:12 vehicle range: 327km Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:12 pv charge current: 5.61A = 0A + 5.61A (-3868W @ 3p) Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:12 pv disable timer reset Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] DEBUG 2024/08/20 12:01:12 pv timer inactive Aug 20 12:01:12 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:12 send evcc: [2,"2640631095","SetChargingProfile",{"connectorId":1,"csChargingProfiles":{"chargingProfileId":1,"stackLevel":1,"chargingProfilePurpose":"TxDefaultProfile","chargingProfileKind":"Absolute","chargingSchedule":{"startSchedule":"2024-08-20T11:01:12Z","chargingRateUnit":"A","chargingSchedulePeriod":[{"startPeriod":0,"limit":6}]}}}] Aug 20 12:01:12 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:12 recv evcc: [3,"2640631095",{"status": "Rejected"}] Aug 20 12:01:12 raspberrypi evcc[637]: [lp-1 ] ERROR 2024/08/20 12:01:12 max charge current 6A: set charging profile: Rejected Aug 20 12:01:35 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:35 recv evcc: [2,"1317886357","Heartbeat",{}] Aug 20 12:01:35 raspberrypi evcc[637]: [ocpp ] TRACE 2024/08/20 12:01:35 send evcc: [3,"1317886357",{"currentTime":"2024-08-20T11:01:35Z"}] Aug 20 12:01:35 raspberrypi evcc[637]: [site ] DEBUG 2024/08/20 12:01:35 ---- [...] ```

What type of operating system are you running?

Linux

Version

evcc version 0.130.1

andig commented 2 months ago

Ursache ist vmtl https://github.com/evcc-io/evcc/pull/14888?

dscho commented 2 months ago

Ursache ist vmtl #14888?

@andig Hätte ich auch gesagt. Auch, dass das genau dieselbe Ursache ist wie bei den anderen Tickets, aber ich linke die jetzt nicht, sonst wird meine Antwort wieder als Off-Topic abgestraft.

andig commented 2 months ago

Kannste gerne verlinken wenns dazu zugehört

andig commented 2 months ago

Folgendes ist passiert:

Ocpp: use ChargingProfileId:1
Ocpp: use ChargingProfileKindAbsolute (#15240)
OCPP: use TxDefaultProfile, add more apis (BC) (#14888)
Ocpp: add transaction id to TxProfile (#9766)
Revert "Ocpp: use default transaction profile (#8549)"
Ocpp: use default transaction profile (#8549)
OCPP: use TxProfile and enable phase switching (#4946) (#4969)

In https://github.com/evcc-io/evcc/pull/14888 gabs eine Änderung von TxProfile auf TxDefaultProfile. In #15240 wurde von relative auf absolute geändert.

Eine der beiden Änderungen sollte ursächlich sein. Könnte das jemand lokal (oder in Docker) testen?

dscho commented 2 months ago

Also ich würde das ja gerne mit git bisect analysieren, aber ganz ehrlich, diese vielen "wip" commits in #14888 sind echt nicht sauber programmiert.

Ich kann mal versuchen, mit git revert zu arbeiten, aber erwarte aufgrund der Qualität und Struktur der Commits Merge-Konflikte, mit denen ich höchstwahrscheinlich dank meiner Unvertrautheit mit der Sprache Go sowie mit der Software-Architektur von EVCC überfordert sein werde.

In jedem Fall muss ich erst mal wieder Auto fahren, damit das laden kann.

andig commented 2 months ago

Mit Verlaub, aber der Kommentar ist nicht angemessen. Zumal die WIPs beim Merge gesquashed werden. Ist also völlig unerheblich.

dscho commented 2 months ago

Mit Verlaub, aber der Kommentar ist nicht angemessen. Zumal die WIPs beim Merge gesquashed werden. Ist also völlig unerheblich.

Der Kommentar ging um die Möglichkeit, git bisect zu verwenden, was ich hier nicht kann.

Es tut mir leid, wenn dabei Gefühle verletzt wurden, das war nicht meine Absicht. Stattdessen wollte ich helfen, aber die Struktur der Commit-Historie, im Verband mit meinem Mangel an Go-Kenntnissen, macht mir das nahezu unmöglich.

premultiply commented 2 months ago

Können wir uns bitte in den Issues einfach nur auf die Problemlösung konzentrieren? Wer alles was nicht kann und will ist für die Sache irrelevant? Im Zweifelsfall bitte einfach raushalten wenn es nichts sachdienliches beizutragen gibt. Wenn das wieder nicht klappt mache ich hier einfach zu oder eine Diskussion draus und dann ist für mich das Thema wirklich erledigt.

Es gibt einen Herstellersupport, der IMMER die erste Anlaufstelle bei Merkwürdigkeiten in der Firmware ist.

andig commented 2 months ago

Der Kommentar ging um die Möglichkeit, git bisect zu verwenden, was ich hier nicht kann.

Das git bisect machst Du auf master. Da sollte es für den PR nur einen Commit geben. Falls nein ist es beim Merge schief gegangen, das hat mir der Entwicklung aber überhaupt nichts zu tun. Danke.

Es gibt einen Herstellersupport, der IMMER die erste Anlaufstelle bei Merkwürdigkeiten in der Firmware ist.

@premultiply das teile ich nicht. Hier ging es mal, jetzt nicht mehr. Die Änderungen sind bei uns und wir sollten raus finden welche Änderung das konkret ist.

premultiply commented 2 months ago

Darum geht es hier. Und bitte nur darum.

premultiply commented 2 months ago

@dscho Bitte mal ein neues Log mit dem aktuellen Nightly anhängen wo sich der Charger nicht im Zustand "Waiting for authentication" ohne existierende Transaktion befindet. Also remotestart: true setzen.

mrhund commented 2 months ago

@dscho Also ich habe das Problem mit meiner Pulsar nicht, ein paar andere Themen - aber das nicht. Daher möchte ich anmerken, dass man im Log sieht, dass du Firmware Version 5.17.87 verwendest, ich habe schon Version 6.4.14. Das könnte ein entscheidender Unterschied sein.

andig commented 2 months ago

@premultiply

    return &types.ChargingProfile{
        ChargingProfileId:      c.chargingProfileId, // <-
        StackLevel:             c.stackLevel, // <-
        ChargingProfilePurpose: types.ChargingProfilePurposeTxDefaultProfile,
        ChargingProfileKind:    types.ChargingProfileKindAbsolute,
        ChargingSchedule: &types.ChargingSchedule{
            StartSchedule:          types.Now(),
            ChargingRateUnit:       c.chargingRateUnit,
            ChargingSchedulePeriod: []types.ChargingSchedulePeriod{period},
        },
    }

Warum kommen hier jeweils die Maxima des im Charger möglichen zum Einsatz und wir verwenden nicht einfach 0 oder 1 wie zuvor?

premultiply commented 2 months ago

Das Stacklevel bestimmt die Priorität des Profils. Damit keine anderen eventuell vorhandenen Profile hineinmischen verwenden wir die höchste Priorität. Andernfalls müsste man bei der Initialsierung erstmal alle vorhanden Profile löschen was wieder ganz andere Probleme (u.a. Ladeunterbrechung oder -start beim Neustart von evcc), Fehler und Unzulänglichkeiten der Firmwares ans Tageslicht spülen dürfte.

Die ChargingProfileId ist im Prinzip (streng nach Standard) völlig egal. Jedoch gab es dann direkt wieder Firmwaren die z.B. nicht mit Wert 0 zurecht kamen... Damit man einen halbwegs gescheiten Defaut-Wert hat, nehmen wir hier hilfsweise die höchste Zahl der zulässigen gleichzeitig installierten Profile - in der Hoffnung dass dies selbst bei verbaselter Stacklevel-Prio oder bei eingeschränktem Value-Range in der Firmware auch die höchste Prio bekommt und evcc andererseits immer die gleiche ChargingProfileId verwendet. Speziell Charger die nur ein ChargingProfile gleichzeitig unterstützen sind da recht empfindlich. Gedanke dahinter: Wenn ein Charger z.B. 10 gleichzeitige Profile erlaubt, dann muss er diese auch mit unterschiedlichen Profile-IDs unterscheiden können und somit wahrscheinlich mindestens einen Value-Range von 1-10 dafür zulassen.

dscho commented 2 months ago

Also ich habe das Problem mit meiner Pulsar nicht, ein paar andere Themen - aber das nicht. Daher möchte ich anmerken, dass man im Log sieht, dass du Firmware Version 5.17.87 verwendest, ich habe schon Version 6.4.14. Das könnte ein entscheidender Unterschied sein.

Ich habe Auto-Update an, und sowohl App als auch Web UI behaupten, das sei up to date:

Ich glaube nicht, dass ich damit alleine bin.

andig commented 2 months ago

...und deshalb müssen wir raus finden, welche der (an sich funktionierenden) Änderungen mit Deiner FW das Problem macht. Nutzt ja nix...

premultiply commented 2 months ago

@dscho Your Firmware seems to be outdated. See https://github.com/evcc-io/evcc/issues/15492#issuecomment-2304528094

cdyna43 commented 2 months ago

Es gibt verschiedene Versionen der Pulsar Plus und verschiedene Firmwares. Bei mir ist auch die 5.17.87 die aktuellste. Habe das bei Wallbox verifiziert.

Ich habe auch genau das gleiche Problem wie dscho.

Zurück zur 0.129.0 und alles funktioniert wieder.

mfuchs1984 commented 2 months ago

Recherchiert man online, gibt's einige Diskussionen um die Firmwareversionen, es scheint unklar zu sein, warum manche die Updates bekommen haben und andere nicht und alle scheinen so ihre Problemchen zu haben. https://community.home-assistant.io/t/wallbox-pulsar-plus-integration/200339/1074?page=54

Leider lassen sich aufgrund eines Fehlers der Website nichtmal die releasnotes aufrufen, soweit man was findet, wurden aber durchaus ocpp Themen adressiert. Evtl macht es unabhängig von der Lösung hier Sinn, mal beim Hersteller nach einer Klärung bzgl. der Versionen zu fragen.

Edit: hat schon jemand gemacht https://github.com/evcc-io/evcc/issues/15492#issuecomment-2304649208

premultiply commented 2 months ago

Ich habe auch genau das gleiche Problem wie dscho.

Und, was sagt der Hersteller dazu?

andig commented 2 months ago

Und, was sagt der Hersteller dazu?

Können wir uns das bitte sparen?

Spricht irgendwas dagegen, dass wir herausfinden, welche Änderung das Problem verursacht? Ohne wird es ohnehin schwierig, von irgendeinem Hersteller dieser Welt eine sinnvolle Antwort zu erhalten.

Danke.

andig commented 2 months ago

@dscho siehe https://github.com/evcc-io/evcc/issues/15581#issuecomment-2304104933

Alles Andere ist jetzt irrelevant.

premultiply commented 2 months ago

Vielleicht kann uns auch @cdyna43 mit einem aktuellen Tracelog des aktuellen Nightly Build aushelfen?

cdyna43 commented 2 months ago

Wenn mir jemand für Dummies erklärt, was ich tun soll, gerne. Ich habe aber evcc zurück auf 0.129.0 gesetzt, damit es wieder funktioniert...

premultiply commented 2 months ago

Schau mal hier: https://docs.evcc.io/docs/faq#wie-kann-ich-ein-logfile-zur-fehleranalyse-erstellen

cdyna43 commented 2 months ago

Wie ich ein Logfile erstelle, weiß ich sogar. Ich müsste dafür aber wieder die aktuelle (nicht funktionierende) Version einspielen, nehme ich an. Und dann brauche ich natürlich Sonne... Ich schaue mal, ob ich das morgen schaffe.

highendsyl commented 2 months ago

Ich habe das gleiche Problem mit Wallbox Commander2. Kann ich Hilfen?

andig commented 2 months ago

Weiterhin https://github.com/evcc-io/evcc/issues/15581#issuecomment-2305180087.

Falls jemand compilieren kann würde es auch helfen, commits adf90ecccd44156da4016af7d2d7b1bbf116af81, d0b58ba883a28f49894e907ff14b37cf24b468c7, 1515a67fc0e7446a076e9c0690bdb98c76d122e3 und 568c5646a8f15d2ded18c1c77eec6c0471000315. Das sind jeweils die Commits vor/nach breaking Changes. Damit könnten wir die Ursache mal eingrenzen.

highendsyl commented 2 months ago

evcc.log

andig commented 2 months ago

@highendsyl wir waren nicht klar genug :(. Es braucht ocpp auf trace.

highendsyl commented 2 months ago

1.000x Sorry: wie mache ich das? Ich helfe gerne und schnell, aber bin mega-junior mit Rpi

andig commented 2 months ago

In dem du das einfach in der Benutzeroberfläche auswählst…

andig commented 2 months ago

Oder in die Doku schaust: https://docs.evcc.io/docs/faq#wie-kann-ich-ein-logfile-zur-fehleranalyse-erstellen

cdyna43 commented 2 months ago

Das Problem von highendsyl (vermute ich) und mir ist, dass das hier "Es braucht ocpp auf trace" leider für uns (jedenfalls mich) nicht verständlich ist. Da hilft mir der Link auch nicht, da es wohl nicht um das normale Logfile geht. Ich habe jetzt auf die 0.130.2 aktualisiert und der Fehler besteht. In EVCC die Logs auf Trace gestellt und den Download-Button gedrückt. Nur wo ist jetzt die Datei gespeichert...?

cdyna43 commented 2 months ago

Das hier? Trace und ocpp ausgewählt...

evcc-20240824-102649-trace.log.txt

andig commented 2 months ago

Nein, nein und nein. Es braucht bitte alle relevanten Komponenten- site, loadpoint und ocpp.

highendsyl commented 2 months ago

evcc-20240824-103501-trace.log.txt

highendsyl commented 2 months ago

Lieber Andig, ist das was du brauchst?

cdyna43 commented 2 months ago

Sorry. Dann noch einmal für mich: Ich wähle bei Log "Trace" aus und bei Bereich zur Sicherheit alles (habe nur die PV-Anlage, die Wallboxen und die Autos)?

evcc-20240824-110226-trace.log.txt

Falls irgendwie von Interesse, hier das entspreche Log mit der funktionierenden 0.129.0:

evcc-20240824-110744-trace.log.txt

mfuchs1984 commented 2 months ago

@highendsyl hast du remotestart: true in der charger config?

andig commented 2 months ago

Lieber Andig, ist das was du brauchst?

Jetzt bitte noch ab Start und ohne http- dann wirds leichter lesbar und vollständig :)

highendsyl commented 2 months ago

evcc-20240824-124018-trace.log.txt

andig commented 2 months ago

Keine neuen Erkenntnisse. Die WB mag SetChargingProfile nicht. Es ist unklar, was genau sie daran nicht mag. Entweder:

findet jemand raus welche Änderung genau die Box nicht mag
gelingt das FW-Update von dem wir wissen, dass es funktioniert
oder bewegt den Hersteller dazu eine Aussage zu treffen

Für uns gibts hier grad nix zu tun. Ich würde das Issue mangels neuer Erkenntnisse dann schließen.

MilkoKA commented 2 months ago

Nur zur Info Ich habe dauch das Problem mit der der Firmware Version 5.17.87. Mir wird ebenfalls keine neue Firmware angeboten und auf Nachfrage bei Wallbox lautete die Antword, dass bei meiner Seriennummer die Firmware Version 5.17.87 die aktuellste Firmware wäre.

Hoffentlich wird das Problem gefunden. Ich geh erstmal auf die 0.129.0 zurück. Viel Glück

andig commented 2 months ago

Für uns gibts hier grad nix zu tun. Ich würde das Issue mangels neuer Erkenntnisse dann schließen.

Nur wenn jemand sucht...

matti1993 commented 2 months ago

Nur zur Info Ich habe dad das Problem mit der Firmware Version 5.17.87. Mir wird ebenfalls keine neue Firmware angeboten und auf Nachfrage bei Wallbox lautete das Antword, dass bei meiner Seriennummer die Firmware Version 5.17.87 die aktuellste Firmware wäre.

Hoffentlich wird das Problem gefunden. Ich geh erstmal auf die 0.129.0 zurück. Viel Glück

Kann mir jemand erklären wie ich wieder auf 0.129.0 zurück komme?

MilkoKA commented 2 months ago

Hi, falls mann die Firmwareversion abfragen kann, könnte man vielleicht sowas bauen wie:

If FW<6 = alteMetode else neu Metode

Ich denke bei der PulsarPlus gibte sowas wie Hardware Gen1 und Gen2. Gen1 wird wohl keine neuen Firmware bekommen.

Ich mache dazu aber ein Anfrage bei Wallbox.com Gruß Milko

andig commented 2 months ago

Auch dafür müsste man rausfinden, was genau "alte Methode" heisst bzw. warum genau die neue nicht funktioniert...

MilkoKA commented 2 months ago

Ich dachte nur, da die 128.4 funktioniert und die 129.0 nicht mehr. wurde denn auch in der 128.4 "SetChargingProfile" benutzt um von aus/pv/min+PV/schnell umzuschalten?

das ich einen Smart#1 fahre kann ich auf der 128.4 bleiben und die Pulsarplus steuern aber bekomme keinen SOC mehr angezeigt. oder auf die neue wechseln und bekommen SOC aber kann die Profile nicht mehr schalten.

highendsyl commented 2 months ago

Trace von 0.128.4 wo alles funktioniert evcc-20240825-183326-trace.log.txt evcc-20240825-183713-trace.log.txt evcc-20240825-183757-trace.log.txt evcc-20240825-183936-trace.log.txt evcc-20240825-184223-trace.log.txt

evcc-io / evcc