OpenEVSE / openevse_esp32_firmware

OpenEVSE V4 WiFi gateway using ESP32
170 stars 112 forks source link

OCPP crash when unplugging EV #756

Closed ealmiladi closed 11 months ago

ealmiladi commented 11 months ago

V5.0.0 I'm having an issue where I stop receiving OCPP events whenever I unplug an EV and the following event comes through:

StatusNotification: {
  connectorId: 1,
  errorCode: 'NoError',
  status: 'SuspendedEV',
  timestamp: '2023-10-29T23:32:18.064Z'
}

I'm expecting a StatusNotification with status 'Finishing' to follow, but it appears as if the there's been a crash on the client side as the EVSE seems to stop broadcasting heartbeat events completely thereafter.

Any guidance on this would be helpful.

Thanks.

matth-x commented 11 months ago

Hi @ealmiladi,

To track this down, does the network controller reboot in this case, i.e. the LEDs flash? And can you open the OpenEVSE debug console (in the debug page) and copy the debug text at the time when this issue occurs? This would help me find out what's going on here.

ealmiladi commented 11 months ago

Hi @ealmiladi,

To track this down, does the network controller reboot in this case, i.e. the LEDs flash? And can you open the OpenEVSE debug console (in the debug page) and copy the debug text at the time when this issue occurs? This would help me find out what's going on here.

I can't tell if the network controller is rebooting--if I had to guess, no. Here are the logs:

[AO] info (StatusNotification.cpp:49): New status: SuspendedEV (connectorId 1)
{"state":1,"flags":512,"vehicle":0,"colour":2,"pilot":6,"max_current":48,"manual_override":1,"status":"active","elapsed":335,"amp":0,"voltage":240,"power":0}
{"session_elapsed":0,"session_energy":0,"total_energy":38.91531926,"total_day":0.735169451,"total_week":5.259623372,"total_month":38.91531926,"total_year":38.91531926,"total_switches":55}
[AO] info (Connector.cpp:277): Session mngt: trigger StopTransaction
[AO] info (StopTransaction.cpp:50): StopTransaction initiated
{"claims_version":4}
{"pilot":48}
{"rfid_auth":""}
{"total_switches":56}
{"state":254,"flags":512,"vehicle":0,"colour":5,"pilot":48,"max_current":48,"manual_override":0,"status":"disabled","elapsed":0,"amp":0,"voltage":240,"power":0}
[AO] info (StatusNotification.cpp:49): New status: Available (connectorId 1)
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
{"evse_connected":1,"amp":0,"voltage":240,"power":0,"pilot":48,"max_current":48,"temp":173,"temp_max":174,"temp1":false,"temp2":173,"temp3":false,"temp4":false,"state":254,"status":"disabled","flags":512,"vehicle":0,"colour":5,"manual_override":0,"freeram":152576,"divertmode":1,"srssi":-72,"time":"2023-10-30T15:51:21Z","local_time":"2023-10-30T10:51:21-0500","offset":"-0500","uptime":162,"session_elapsed":0,"session_energy":0,"total_energy":38.91531926,"total_day":0.735169451,"total_week":5.259623372,"total_month":38.91531926,"total_year":38.91531926,"total_switches":56,"elapsed":0,"wattsec":0,"watthour":38915.31926}
{"session_elapsed":0,"session_energy":0,"total_energy":38.91531926,"total_day":0.735169451,"total_week":5.259623372,"total_month":38.91531926,"total_year":38.91531926,"total_switches":56}
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] info (RequestQueue.cpp:45): operation timeout: Heartbeat
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
{"evse_connected":1,"amp":0,"voltage":240,"power":0,"pilot":48,"max_current":48,"temp":175,"temp_max":175,"temp1":false,"temp2":175,"temp3":false,"temp4":false,"state":254,"status":"disabled","flags":512,"vehicle":0,"colour":5,"manual_override":0,"freeram":155556,"divertmode":1,"srssi":-71,"time":"2023-10-30T15:51:52Z","local_time":"2023-10-30T10:51:52-0500","offset":"-0500","uptime":193,"session_elapsed":0,"session_energy":0,"total_energy":38.91531926,"total_day":0.735169451,"total_week":5.259623372,"total_month":38.91531926,"total_year":38.91531926,"total_switches":56,"elapsed":0,"wattsec":0,"watthour":38915.31926}
{"session_elapsed":0,"session_energy":0,"total_energy":38.91531926,"total_day":0.735169451,"total_week":5.259623372,"total_month":38.91531926,"total_year":38.91531926,"total_switches":56}
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] info (RequestQueue.cpp:45): operation timeout: Heartbeat
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
[AO] ERROR (StopTransaction.cpp:211): Server error, data loss!
matth-x commented 11 months ago

Oh that's more than helpful. The server cannot process the StopTransaction request and replies with an error. At the moment, the OCPP lib has no better strategy than retrying until the request goes through finally, but in this case it will end up stalling the request queue forever.

Do the server logs show the raw incoming traffic and can you copy the problematic StopTransaction request here? It's a common thing with OCPP that different interpretations of the standard lead to such problems. In case it's an issue on our side I'll fix it.

ealmiladi commented 11 months ago

Oh that's more than helpful. The server cannot process the StopTransaction request and replies with an error. At the moment, the OCPP lib has no better strategy than retrying until the request goes through finally, but in this case it will end up stalling the request queue forever.

Do the server logs show the raw incoming traffic and can you copy the problematic StopTransaction request here? It's a common thing with OCPP that different interpretations of the standard lead to such problems. In case it's an issue on our side I'll fix it.

Oh! There was an exception occurring in my server handler for StopTransaction which was throwing silently and therefore I missed it. My apologies!!! I appreciate you taking a look and great work the ArduinoOCPP / OpenEVSE implementation!