Multiple 'Start Charging' actions sometimes needed

[GrantKeymer]

This is something I've noticed several times now, but it doesn't always occur. Sometimes I need to press 'Start Charging' several times before it is actioned. Eventually it always works, but there is no telling how many times I need to try before anything happens. Yesterday, my Pulsar Plus took 3 attempts before it started charging. Today it worked first time. I am running the latest version of the integration 0.4.29.

Below are the logs from yesterday. I cannot see what the integration is doing differently between the first, second and third attempts.
To me it seems like a charger bug. Thoughts?

2022-04-14 09:32:14 INFO (MainThread) [ocpp] : send [2,"e8a9ab7f-18e7-4134-b4ad-302b4fd2306a","GetConfiguration",{"key":["AuthorizeRemoteTxRequests"]}]
2022-04-14 09:32:14 DEBUG (MainThread) [websockets.server] > TEXT '[2,"e8a9ab7f-18e7-4134-b4ad-302b4fd2306a","GetC...izeRemoteTxRequests"]}]' [99 bytes]
2022-04-14 09:32:14 DEBUG (MainThread) [websockets.server] < TEXT '[3,"e8a9ab7f-18e7-4134-b4ad-302b4fd2306a",\n{\n...ue": "false"\n} \n]\n}]' [166 bytes]
2022-04-14 09:32:14 INFO (MainThread) [ocpp] : receive message [3,"e8a9ab7f-18e7-4134-b4ad-302b4fd2306a",
{
"unknownKey": [],
"configurationKey": [
{
"readonly": false,
"key": "AuthorizeRemoteTxRequests",
"value": "false"
}
]
}]
2022-04-14 09:32:14 INFO (MainThread) [ocpp] : send [2,"908f05bd-8680-4d2a-b77b-7d665c63893c","RemoteStartTransaction",{"idTag":"","connectorId":1}]
2022-04-14 09:32:14 DEBUG (MainThread) [websockets.server] > TEXT '[2,"908f05bd-8680-4d2a-b77b-7d665c63893c","Remo...g":"","connectorId":1}]' [96 bytes]
2022-04-14 09:32:14 DEBUG (MainThread) [websockets.server] < TEXT '[3,"908f05bd-8680-4d2a-b77b-7d665c63893c",\n{\n"status": "Accepted"\n}]' [68 bytes]
2022-04-14 09:32:14 INFO (MainThread) [ocpp] : receive message [3,"908f05bd-8680-4d2a-b77b-7d665c63893c",
{
"status": "Accepted"
}]
2022-04-14 09:32:18 DEBUG (MainThread) [websockets.server] > PING 5a 54 f5 f6 [binary, 4 bytes]
2022-04-14 09:32:18 DEBUG (MainThread) [websockets.server] < PONG 5a 54 f5 f6 [binary, 4 bytes]
2022-04-14 09:32:20 DEBUG (MainThread) [websockets.server] < PING '1649885540' [text, 10 bytes]
2022-04-14 09:32:20 DEBUG (MainThread) [websockets.server] > PONG '1649885540' [text, 10 bytes]

...

2022-04-14 09:32:34 INFO (MainThread) [ocpp] : send [2,"9b934fa4-9379-4d56-a2ec-983f9d921989","GetConfiguration",{"key":["AuthorizeRemoteTxRequests"]}]
2022-04-14 09:32:34 DEBUG (MainThread) [websockets.server] > TEXT '[2,"9b934fa4-9379-4d56-a2ec-983f9d921989","GetC...izeRemoteTxRequests"]}]' [99 bytes]
2022-04-14 09:32:34 DEBUG (MainThread) [websockets.server] < TEXT '[3,"9b934fa4-9379-4d56-a2ec-983f9d921989",\n{\n...ue": "false"\n} \n]\n}]' [166 bytes]
2022-04-14 09:32:34 INFO (MainThread) [ocpp] : receive message [3,"9b934fa4-9379-4d56-a2ec-983f9d921989",
{
"unknownKey": [],
"configurationKey": [
{
"readonly": false,
"key": "AuthorizeRemoteTxRequests",
"value": "false"
}
]
}]
2022-04-14 09:32:34 INFO (MainThread) [ocpp] : send [2,"9b963d83-9b6b-4eb7-990d-334fcb905a11","RemoteStartTransaction",{"idTag":"","connectorId":1}]
2022-04-14 09:32:34 DEBUG (MainThread) [websockets.server] > TEXT '[2,"9b963d83-9b6b-4eb7-990d-334fcb905a11","Remo...g":"","connectorId":1}]' [96 bytes]
2022-04-14 09:32:34 DEBUG (MainThread) [websockets.server] < TEXT '[3,"9b963d83-9b6b-4eb7-990d-334fcb905a11",\n{\n"status": "Accepted"\n}]' [68 bytes]
2022-04-14 09:32:34 INFO (MainThread) [ocpp] : receive message [3,"9b963d83-9b6b-4eb7-990d-334fcb905a11",
{
"status": "Accepted"
}]
2022-04-14 09:32:38 DEBUG (MainThread) [websockets.server] > PING fa 42 ee ba [binary, 4 bytes]
2022-04-14 09:32:38 DEBUG (MainThread) [websockets.server] < PONG fa 42 ee ba [binary, 4 bytes]
2022-04-14 09:32:43 DEBUG (MainThread) [websockets.server] > PING 12 6e 99 bd [binary, 4 bytes]
2022-04-14 09:32:43 DEBUG (MainThread) [websockets.server] < PONG 12 6e 99 bd [binary, 4 bytes]

...

2022-04-14 09:32:48 INFO (MainThread) [ocpp] : send [2,"ef5b044a-e4f7-4412-91e1-ad787c04e027","GetConfiguration",{"key":["AuthorizeRemoteTxRequests"]}]
2022-04-14 09:32:48 DEBUG (MainThread) [websockets.server] > TEXT '[2,"ef5b044a-e4f7-4412-91e1-ad787c04e027","GetC...izeRemoteTxRequests"]}]' [99 bytes]
2022-04-14 09:32:48 DEBUG (MainThread) [websockets.server] > PING df 15 74 7b [binary, 4 bytes]
2022-04-14 09:33:01 DEBUG (MainThread) [websockets.server] < PONG df 15 74 7b [binary, 4 bytes]
2022-04-14 09:33:01 DEBUG (MainThread) [websockets.server] < TEXT '[3,"ef5b044a-e4f7-4412-91e1-ad787c04e027",\n{\n...ue": "false"\n} \n]\n}]' [166 bytes]
2022-04-14 09:33:01 INFO (MainThread) [ocpp] : receive message [3,"ef5b044a-e4f7-4412-91e1-ad787c04e027",
{
"unknownKey": [],
"configurationKey": [
{
"readonly": false,
"key": "AuthorizeRemoteTxRequests",
"value": "false"
}
]
}]
2022-04-14 09:33:01 INFO (MainThread) [ocpp] : send [2,"d216c3d6-c7f8-4d9d-b9c9-263cfbe57180","RemoteStartTransaction",{"idTag":"","connectorId":1}]
2022-04-14 09:33:01 DEBUG (MainThread) [websockets.server] > TEXT '[2,"d216c3d6-c7f8-4d9d-b9c9-263cfbe57180","Remo...g":"","connectorId":1}]' [96 bytes]
2022-04-14 09:33:01 DEBUG (MainThread) [websockets.server] < TEXT '[3,"d216c3d6-c7f8-4d9d-b9c9-263cfbe57180",\n{\n"status": "Accepted"\n}]' [68 bytes]
2022-04-14 09:33:01 INFO (MainThread) [ocpp] : receive message [3,"d216c3d6-c7f8-4d9d-b9c9-263cfbe57180",
{
"status": "Accepted"
}]
2022-04-14 09:33:03 DEBUG (MainThread) [websockets.server] < TEXT '[2,"855583f7-50b3-4fbb-bdbe-6123f20709c8","Star...2022-04-13T21:33:03Z"}]' [144 bytes]
2022-04-14 09:33:03 INFO (MainThread) [ocpp] : receive message [2,"855583f7-50b3-4fbb-bdbe-6123f20709c8","StartTransaction",{"connectorId": 1,"meterStart": 0,"idTag": "","timestamp": "2022-04-13T21:33:03Z"}]
2022-04-14 09:33:03 INFO (MainThread) [ocpp] : send [3,"855583f7-50b3-4fbb-bdbe-6123f20709c8",{"transactionId":1649885583,"idTagInfo":{"status":"Accepted"}}]
2022-04-14 09:33:03 DEBUG (MainThread) [websockets.server] > TEXT '[3,"855583f7-50b3-4fbb-bdbe-6123f20709c8",{"tra...{"status":"Accepted"}}]' [105 bytes]
2022-04-14 09:33:03 DEBUG (MainThread) [websockets.server] < TEXT '[2,"70ce0583-3bb9-4afe-876f-0ed882d8905c","Stat...2022-04-13T21:33:03Z"}]' [213 bytes]
2022-04-14 09:33:03 INFO (MainThread) [ocpp] : receive message [2,"70ce0583-3bb9-4afe-876f-0ed882d8905c","StatusNotification",{"info": "","vendorId": "","vendorErrorCode": "","connectorId": 1,"errorCode": "NoError","status": "SuspendedEV","timestamp": "2022-04-13T21:33:03Z"}]
2022-04-14 09:33:03 INFO (MainThread) [ocpp] : send [3,"70ce0583-3bb9-4afe-876f-0ed882d8905c",{}]
2022-04-14 09:33:03 DEBUG (MainThread) [websockets.server] > TEXT '[3,"70ce0583-3bb9-4afe-876f-0ed882d8905c",{}]' [45 bytes]
2022-04-14 09:33:03 DEBUG (MainThread) [websockets.server] > PING fb 3a cf 5d [binary, 4 bytes]
2022-04-14 09:33:04 DEBUG (MainThread) [websockets.server] < PONG fb 3a cf 5d [binary, 4 bytes]
2022-04-14 09:33:05 DEBUG (MainThread) [websockets.server] < TEXT '[2,"db30a8cb-88e8-4cfe-8cda-246f9b0241c0","Stat...2022-04-13T21:33:05Z"}]' [210 bytes]
2022-04-14 09:33:05 INFO (MainThread) [ocpp] : receive message [2,"db30a8cb-88e8-4cfe-8cda-246f9b0241c0","StatusNotification",{"info": "","vendorId": "","vendorErrorCode": "","connectorId": 1,"errorCode": "NoError","status": "Charging","timestamp": "2022-04-13T21:33:05Z"}]
2022-04-14 09:33:05 INFO (MainThread) [ocpp] : send [3,"db30a8cb-88e8-4cfe-8cda-246f9b0241c0",{}]
2022-04-14 09:33:05 DEBUG (MainThread) [websockets.server] > TEXT '[3,"db30a8cb-88e8-4cfe-8cda-246f9b0241c0",{}]' [45 bytes]
2022-04-14 09:33:09 DEBUG (MainThread) [websockets.server] > PING 'еҊ' [text, 4 bytes]
2022-04-14 09:33:09 DEBUG (MainThread) [websockets.server] < PONG 'еҊ' [text, 4 bytes]
2022-04-14 09:33:14 DEBUG (MainThread) [websockets.server] > PING 1a 15 89 df [binary, 4 bytes]
2022-04-14 09:33:14 DEBUG (MainThread) [websockets.server] < PONG 1a 15 89 df [binary, 4 bytes]

[drc38]

Have you tried rebooting the charger, looks like it is slow to respond/process the incoming RemoteStartTransaction request? Could it be linked to your faster polling setting?

[GrantKeymer]

I've definitely rebooted the charger several times during the period I've noticed this issue and that didn't help. But it might be worth increasing the Ping Interval again and see if that helps.

Thanks and Happy Easter 🐰