CALLRESULT error about microocpp

[matth-x]

Hi Chaitanya, the error says that the OCPP server has sent a response message which cannot be assigned to a pending operation.

So if your Central System doesn't alter the message IDs (which I strongly assume) the most likely reason is that the client has initiated a Heartbeat operation and the Central System has replied with two identical responses. Then the first response finishes the pending operation and the second one arrives in an empty queue causing that debug message. That's a side effect of package losses with TCP connections and how OCPP is designed to deal with it.

Another possible reason is that the response arrives at the moment when the client cancels the operation because of the timeout or the client has rebooted in the meantime. In all cases it is correct to just discard the incoming response message and do nothing more.

If you enable the AO_TRAFFIC_OUT you can reconstruct the message flow. I would certainly be interested if you find a further case causing that debug message!

[ChaitanyaYeole02]

My OCPP server is a basic Python OCPP server, which is available at https://pypi.org/project/ocpp/

I just saw the logs after enabling AO_TRAFFIC_OUT

[OcppOperation] Sent requirement (success): [2,"531531532","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2021-10-06T06:58:35.000Z"}]
[OcppOperation] Sent requirement (success): [2,"531531532","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2021-10-06T06:58:35.000Z"}]
[OcppClientSocket] get text: [3,"531531532",{}]
[OcppClientSocket] get text: [3,"531531532",{}]
[OcppEngine] Received CALLRESULT doesn't match any pending operation!

[ChaitanyaYeole02]

I think the ID's from the server are the same, The problem is from Charge Point side where is it not able to respond to the CALLRESULT function from the server.
While receiving the CONF message it does not receive properly, I am also looking into it. Will update the same over here

Update
Whenever I reboot my esp this error is received randomly,
These two payloads are sent from the CP Side to server which is wrong.

[OcppOperation] Sent requirement (success): [2,"531531532","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2021-10-06T06:58:35.000Z"}]
[OcppOperation] Sent requirement (success): [2,"531531532","StatusNotification",{"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2021-10-06T06:58:35.000Z"}]

Then I guess if we solve the error of sending multiple requests from CP side this would be resolved!

[OcppClientSocket] get text: [3,"531531532",{}]
[OcppClientSocket] get text: [3,"531531532",{}]
[OcppEngine] Received CALLRESULT doesn't match any pending operation!

[matth-x]

Thank you for the log, it explains everything. The library sends the StatusNotification one time and after a while without response from the server, it assumes a package loss, retries the operation and sends the message a second time. But in your case the package wasn't actually lost, but only delayed longer than the maximum delay. I assume that the OCPP server is unresponsive from time to time.

Due to the design of OCPP, this shouldn't have any side effects, so you can ignore the log message. In future, I might add the option to increase the maximum delay. In the meantime, you can set higher values here. Just increase RETRY_INTERVAL and / or RETRY_INTERVAL_MAX.

The manual about OCPP via WebSockets which comes with the OCPP 1.6 specification explains this messaging mechanism in more detail.

[ChaitanyaYeole02]

Thank you so much, I will try this and let you know

[ChaitanyaYeole02]

It is working great, I have not received any CALLRESULT in last 4-5 hours