openevse_esp32_firmware icon indicating copy to clipboard operation
openevse_esp32_firmware copied to clipboard

When power outage, it give wrong "reason"

Open flyrobot opened this issue 1 year ago • 13 comments

"data" : { "meterStop" : NumberInt(7220), "timestamp" : "transactionId : "reason" : "DeAuthorized"

it supposed to be : "reason" : "PowerLoss"

flyrobot avatar Jan 14 '24 14:01 flyrobot

Hi @flyrobot,

Actually OpenEVSE does not stop the transaction when the controller is reset. Charging will be resumed with the same transaction once the power supply is up again.

"DeAuthorized" means that the OCPP server requested the transaction to stop, not the charger. My guess would be that the power outage is just coincidence here and that the idTag was not recognized by the server in the first place. Can you find further messages in the server logs supporting / negating this?

And do you need OpenEVSE to stop transactions after power outages?

Anyway, thank you very much for reporting bugs!

matth-x avatar Jan 14 '24 19:01 matth-x

This is the further message after DeAuthorized :

Received: [2,"1000004","StopTransaction",{"meterStop":54,"timestamp":"2024-01-15T13:23:28.057Z","transactionId":347,"reason":"DeAuthorized"}] Sending: [3,"1000004",{}] [chargeBoxId=xxxxx, sessionId=6dc2a837-5faa-8495-3417-8e5507c9bf00] Received: [2,"1000005","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Finishing","timestamp":"2024-01-15T13:23:28.666Z"}]

And do you need OpenEVSE to stop transactions after power outages? Im using openevse as technical local ev charger operator, to make openevse pass all the test from local gov authority. to answer this question, i do not know what is best for operator, or it will be better it can be configured in ocpp menu. beside this "probably bug", i still have several question, and will put in other issue

flyrobot avatar Jan 15 '24 13:01 flyrobot

Can you post the preceding Authorize and StartTransaction messages?

Okay, perhaps the blackout behavior is not tested at all. To my understanding the OCPP specs leave this part open and it's more a question of the operator's preference. It would be possible to modify this behavior if required.

matth-x avatar Jan 15 '24 15:01 matth-x

[chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000035","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Preparing","timestamp":"2024-01-15T15:59:20.563Z"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000035",{}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [2,"f8407a95-bf6d-463f-8226-2070458d3720","RemoteStartTransaction",{"connectorId":1,"idTag":"2DA7CD6C"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [3,"f8407a95-bf6d-463f-8226-2070458d3720",{"status":"Accepted"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000036","StartTransaction",{"connectorId":1,"idTag":"2DA7CD6C","meterStart":54,"timestamp":"2024-01-15T15:59:35.770Z"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000036",{"transactionId":352,"idTagInfo":{"status":"Accepted","expiryDate":"2024-01-31T00:00:00.000Z"}}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000037","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"SuspendedEVSE","timestamp":"2024-01-15T15:59:36.517Z"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000037",{}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000038","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"SuspendedEV","timestamp":"2024-01-15T15:59:38.248Z"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000038",{}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000039","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Charging","timestamp":"2024-01-15T15:59:38.483Z"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000039",{}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [2,"b740fb86-2dbb-41fe-a2d7-a10b53ee9172","RemoteStopTransaction",{"transactionId":352}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [3,"b740fb86-2dbb-41fe-a2d7-a10b53ee9172",{"status":"Accepted"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000040","StopTransaction",{"meterStop":54,"timestamp":"2024-01-15T15:59:48.684Z","transactionId":352,"reason":"Remote"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000040",{}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000041","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Finishing","timestamp":"2024-01-15T15:59:49.472Z"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000041",{}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Received: [2,"1000042","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2024-01-15T15:59:57.979Z"}] [chargeBoxId=xxxxx, sessionId=d620d3d6-f21c-0cb3-d60d-236758494982] Sending: [3,"1000042",{}]

flyrobot avatar Jan 15 '24 16:01 flyrobot

Can you post the preceding Authorize and StartTransaction messages?

Okay, perhaps the blackout behavior is not tested at all. To my understanding the OCPP specs leave this part open and it's more a question of the operator's preference. It would be possible to modify this behavior if required.

yes please modify this behavior, otherwise it considered not pass ocpp standard

flyrobot avatar Jan 15 '24 16:01 flyrobot

Before the StopTransaction with reason DeAuthorized I would expect an Authorize response or StartTransaction response with idTagInfo, status Invalid (or anything but Accepted). The logs from above look okay.

Are you able to compile the sources? The blackout behavior can be changed by always ending the possibly ongoing transaction from previous runs during the boot phase.

Add

endTransaction("PowerLoss");

after these lines:

https://github.com/OpenEVSE/openevse_esp32_firmware/blob/f4a3d3114b5d1e37c1d66568bd710d024b4a90e3/src/ocpp.cpp#L116-L123

matth-x avatar Jan 15 '24 17:01 matth-x

Yes i can compile the source. give the result here

flyrobot avatar Jan 16 '24 01:01 flyrobot

on Last report above im using openevse_wifi_v1 using stock firmware, now I compile using nodeMCU-32S (why LCD become dark ???) with ocpp.cpp edited, the moment charging transaction is in progress and turn off the power :

[chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Connection is established [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Received: [2,"1000000","BootNotification",{"chargePointModel":"Advanced Series","chargePointSerialNumber":"782184D49C10","chargePointVendor":"OpenEVSE","firmwareVersion":"local___modified","meterSerialNumber":""}] The boot of the chargebox 'xxxxx' with registration status 'Optional[ACCEPTED]' is acknowledged. [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Sending: [3,"1000000",{"status":"Accepted","currentTime":"2024-01-16T13:38:13.618Z","interval":14400}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Received: [2,"1000001","StartTransaction",{"connectorId":1,"idTag":"DefaultIdTag","meterStart":0,"timestamp":"2024-01-16T13:38:12.618Z"}] The user with idTag 'DefaultIdTag' is BLOCKED. [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Sending: [3,"1000001",{"transactionId":363,"idTagInfo":{"status":"Blocked","expiryDate":"2024-01-16T14:38:14.062Z"}}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Received: [2,"1000002","StatusNotification",{"connectorId":0,"errorCode":"NoError","status":"Available","timestamp":"2024-01-16T13:38:02.752Z"}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Sending: [3,"1000002",{}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Received: [2,"1000003","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"SuspendedEVSE","timestamp":"2024-01-16T13:38:13.754Z"}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Sending: [3,"1000003",{}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Received: [2,"1000004","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"SuspendedEV","timestamp":"2024-01-16T13:38:13.978Z"}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Sending: [3,"1000004",{}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Received: [2,"1000005","StopTransaction",{"meterStop":0,"timestamp":"2024-01-16T13:38:14.346Z","transactionId":363,"reason":"DeAuthorized"}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Sending: [3,"1000005",{}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Received: [2,"1000006","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Finishing","timestamp":"2024-01-16T13:38:14.997Z"}] [chargeBoxId=xxxxx, sessionId=66a6454a-ac0f-e283-88cd-1c2cd4112940] Sending: [3,"1000006",{}]

still "reason":"DeAuthorized"

flyrobot avatar Jan 16 '24 13:01 flyrobot

In the IdTags menu of SteVe, look for the entry DefaultIdTag and unblock it. If DefaultIdTag does not exist yet, create it.

Alternatively, in the auto-authorization settings of OpenEVSE, you can enter an existing idTag.

matth-x avatar Jan 16 '24 15:01 matth-x

i tried to turn off power while in charging status (in transaction)

The user with idTag '2DA7CD6C' is ALREADY in another transaction(s). [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Sending: [3,"1000001",{"transactionId":377,"idTagInfo":{"status":"ConcurrentTx","expiryDate":"2024-01-17T06:15:25.817Z"}}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Received: [2,"1000002","StatusNotification",{"connectorId":0,"errorCode":"NoError","status":"Available","timestamp":"2024-01-17T05:15:13.535Z"}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Sending: [3,"1000002",{}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Received: [2,"1000003","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"SuspendedEVSE","timestamp":"2024-01-17T05:15:25.537Z"}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Sending: [3,"1000003",{}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Received: [2,"1000004","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"SuspendedEV","timestamp":"2024-01-17T05:15:25.762Z"}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Sending: [3,"1000004",{}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Received: [2,"1000005","StopTransaction",{"meterStop":54,"timestamp":"2024-01-17T05:15:26.378Z","transactionId":377,"reason":"DeAuthorized"}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Sending: [3,"1000005",{}] [chargeBoxId=xxxxx, sessionId=6c7b491d-f1ea-8775-4c4d-c153931b403b] Received: [2,"1000006","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Finishing","timestamp":"2024-01-17T05:15:26.852Z"}]

flyrobot avatar Jan 17 '24 05:01 flyrobot

Before the StopTransaction with reason DeAuthorized I would expect an Authorize response or StartTransaction response with idTagInfo, status Invalid (or anything but Accepted). The logs from above look okay.

Are you able to compile the sources? The blackout behavior can be changed by always ending the possibly ongoing transaction from previous runs during the boot phase.

Add

endTransaction("PowerLoss");

after these lines:

https://github.com/OpenEVSE/openevse_esp32_firmware/blob/f4a3d3114b5d1e37c1d66568bd710d024b4a90e3/src/ocpp.cpp#L116-L123

after i try give "//" , compile and upgrade via GUI, seem success uploading but now the board (openevse_wifi_v1 is dead) after boot up. Total dead, nothings is live. its weird.

flyrobot avatar Jan 17 '24 10:01 flyrobot

Seems like a boot loop, i.e. something crashes the ESP during boot / shortly afterwards. Are you able to isolate the problematic line?

If you view the debug output via UART, you should see the stack trace at the point of the crash.

matth-x avatar Jan 21 '24 19:01 matth-x

Agree blackout behavior needs to be tested for each release. It’s an important test that needs to pass before the EVSE can be used for public charging.

TechnicalLee avatar Jan 27 '24 21:01 TechnicalLee