c-jimenez/open-ocpp

The FIFO module crashes when processing offline messages.

JamesLebron opened this issue · 2 comments

JamesLebron commented

Dear author,

Hello.

We have found that after the system goes offline and comes back online, there is a crash when processing offline messages. We have tried to identify patterns and reasons for the occurrence but have not found any. However, we have captured some logs before the crash.

Could you provide us with some guidance and suggestions for troubleshooting?

[[ DEBUG ][ - [2024-01-11 08:00:40.586] - InternalConfigManager.cpp:182 - Key : StackVersion = 1.0.0
[[ DEBUG ][ - [2024-01-11 08:00:40.755] - InternalConfigManager.cpp:182 - Key : LastSessionStartDate = 2024-01-10T23:26:23Z
[[ DEBUG ][ - [2024-01-11 08:00:40.795] - InternalConfigManager.cpp:182 - Key : LastSessionUpTime = 2010
[[ DEBUG ][ - [2024-01-11 08:00:40.835] - InternalConfigManager.cpp:182 - Key : LastSessionDisconnectedTime = 199
[[ DEBUG ][ - [2024-01-11 08:00:40.875] - InternalConfigManager.cpp:182 - Key : TotalUpTime = 33450
[[ DEBUG ][ - [2024-01-11 08:00:40.926] - InternalConfigManager.cpp:182 - Key : TotalDisconnectedTime = 1350
[[ DEBUG ][ - [2024-01-11 08:00:40.967] - InternalConfigManager.cpp:182 - Key : LastConnectionUrl = ws://192.168.10.10:8080/ocpp/
[[ DEBUG ][ - [2024-01-11 08:00:41.015] - InternalConfigManager.cpp:182 - Key : LastRegistrationStatus = Accepted
[[ DEBUG ][ - [2024-01-11 08:00:41.055] - InternalConfigManager.cpp:182 - Key : LAST_CONNECTION_IFACE = eth1
[[ DEBUG ][ - [2024-01-11 08:00:41.095] - InternalConfigManager.cpp:182 - Key : LocalListVersion = 0
[[ DEBUG ][ - [2024-01-11 08:00:41.135] - InternalConfigManager.cpp:182 - Key : SignedFirmwareUpdateId = 
[[ DEBUG ][ - [2024-01-11 08:00:41.178] - Connectors.cpp:253 - Connector 0 loaded from database : status = Available - last_notified_status = Unavailable - transaction_id = 0 - transaction_id_offline = 0 - transaction_start = 1970-01-01T00:00:00Z - transaction_id_tag =  - transaction_parent_id_tag =  - reservation_id = 0 - reservation_id_tag =  - reservation_parent_id_tag =  - reservation_expiry_date = 1970-01-01T00:00:00Z
[[ DEBUG ][ - [2024-01-11 08:00:41.229] - Connectors.cpp:253 - Connector 1 loaded from database : status = Finishing - last_notified_status = Charging - transaction_id = 0 - transaction_id_offline = 0 - transaction_start = 1970-01-01T00:00:00Z - transaction_id_tag =  - transaction_parent_id_tag =  - reservation_id = 0 - reservation_id_tag =  - reservation_parent_id_tag =  - reservation_expiry_date = 2024-01-10T09:06:49Z
[[ DEBUG ][ - [2024-01-11 08:00:41.276] - Connectors.cpp:253 - Connector 2 loaded from database : status = Available - last_notified_status = Preparing - transaction_id = 0 - transaction_id_offline = 0 - transaction_start = 1970-01-01T00:00:00Z - transaction_id_tag =  - transaction_parent_id_tag =  - reservation_id = 0 - reservation_id_tag =  - reservation_parent_id_tag =  - reservation_expiry_date = 2024-01-10T09:08:33Z
[[ INFO  ][ - [2024-01-11 08:00:41.320] - RequestFifo.cpp:176 - Transaction related request FIFO : 0 message(s) pending
HMIManager set workpath=/app/ocpp_config/certificates
[[ INFO  ][ - [2024-01-11 08:00:41.367] - ChargePoint.cpp:216 - Starting OCPP stack v1.0.0 - Central System : ws://192.168.10.10:8080/ocpp - Charge Point identifier : 23859016
[[ DEBUG ][ - [2024-01-11 08:00:41.675] - MessageDispatcher.cpp:52 - [GetConfiguration] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:41.717] - MessageDispatcher.cpp:52 - [ChangeConfiguration] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:41.760] - MessageDispatcher.cpp:52 - [TriggerMessage] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:41.807] - MessageDispatcher.cpp:52 - [ExtendedTriggerMessage] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:41.849] - MessageDispatcher.cpp:52 - [ClearCache] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:41.895] - MessageDispatcher.cpp:52 - [GetLocalListVersion] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:41.939] - MessageDispatcher.cpp:52 - [SendLocalList] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:41.985] - AuthentLocalList.cpp:66 - Authent local list version : 0
[[ DEBUG ][ - [2024-01-11 08:00:42.028] - MessageDispatcher.cpp:52 - [ChangeAvailability] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.075] - MessageDispatcher.cpp:52 - [ReserveNow] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.113] - MessageDispatcher.cpp:52 - [CancelReservation] Validator loaded
[[ INFO  ][ - [2024-01-11 08:00:42.158] - MeterValuesManager.cpp:319 - Configure clock aligned meter values : interval in seconds = 30
[[ INFO  ][ - [2024-01-11 08:00:42.219] - MeterValuesManager.cpp:325 - Thu Jan 11 08:01:00 2024

[[ DEBUG ][ - [2024-01-11 08:00:42.270] - MessageDispatcher.cpp:52 - [ClearChargingProfile] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.325] - MessageDispatcher.cpp:52 - [SetChargingProfile] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.367] - MessageDispatcher.cpp:52 - [GetCompositeSchedule] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.409] - MessageDispatcher.cpp:52 - [RemoteStartTransaction] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.456] - MessageDispatcher.cpp:52 - [RemoteStopTransaction] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.500] - MessageDispatcher.cpp:52 - [DataTransfer] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.600] - MessageDispatcher.cpp:52 - [Reset] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.639] - MessageDispatcher.cpp:52 - [UnlockConnector] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.679] - MessageDispatcher.cpp:52 - [GetDiagnostics] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.718] - MessageDispatcher.cpp:52 - [UpdateFirmware] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.760] - MessageDispatcher.cpp:52 - [GetLog] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.815] - MessageDispatcher.cpp:52 - [SignedUpdateFirmware] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.849] - MaintenanceManager.cpp:112 - Signed firmare update request id : No signed firmware update in progress
[[ DEBUG ][ - [2024-01-11 08:00:42.897] - MessageDispatcher.cpp:52 - [CertificateSigned] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.939] - MessageDispatcher.cpp:52 - [DeleteCertificate] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:42.991] - MessageDispatcher.cpp:52 - [GetInstalledCertificateIds] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:43.035] - MessageDispatcher.cpp:52 - [InstallCertificate] Validator loaded
[[ DEBUG ][ - [2024-01-11 08:00:43.099] - Connectors.cpp:303 - Connector 1 updated in database
[[ INFO  ][ - [2024-01-11 08:00:43.146] - ChargePoint.cpp:1224 - connect websokect,interface:eth1,connection_url:ws://192.168.10.10:8080/ocpp/,chargePointIdentifier:23859016,AuthenticationKey:123456789,security_profile:2
[2024/01/11 08:00:43:1912] N: lws_create_context: LWS: 4.3.2-v1.2.0-276-g82dd33b, NET CLI SRV H1 H2 WS ConMon IPv6-absent
[2024/01/11 08:00:43:1944] N: __lws_lc_tag:  ++ [wsi|0|pipe] (1)
[2024/01/11 08:00:43:2633] N: __lws_lc_tag:  ++ [vh|0|default|eth1|eth1|-1] (1)
[2024/01/11 08:00:43:3448] N: __lws_lc_tag:  ++ [wsicli|0|WS/h1/default/192.168.10.10] (1)
[[ INFO  ][ - [2024-01-11 08:00:44.078] - MeterValuesManager.cpp:319 - Configure clock aligned meter values : interval in seconds = 30
[[ INFO  ][ - [2024-01-11 08:00:44.113] - MeterValuesManager.cpp:325 - Thu Jan 11 08:01:00 2024
[[ INFO  ][ - [2024-01-11 08:00:44.089] - MeterValuesManager.cpp:319 - Configure clock aligned meter values : interval in seconds = 30
[[ INFO  ][ - [2024-01-11 08:00:44.129] - MeterValuesManager.cpp:325 - Thu Jan 11 08:01:00 2024
[[ ERROR ][ - [2024-01-11 08:01:02.023] - ChargePoint.cpp:933 - Connection failed with Central System
[[ INFO  ][ - [2024-01-11 08:01:02.064] - ChargePoint.cpp:942 - Last registration status was accepted, offline actions are allowed
[[ INFO  ][ - [2024-01-11 08:01:02.043] - MeterValuesManager.cpp:319 - Configure clock aligned meter values : interval in seconds = 30
[[ INFO  ][ - [2024-01-11 08:01:02.093] - MeterValuesManager.cpp:325 - Thu Jan 11 08:01:30 2024
[[ INFO  ][ - [2024-01-11 08:01:02.225] - main.cpp:644 - ConnectorId:1; Event:LocalStop; CurrentStatus:IDLE
[[ INFO  ][ - [2024-01-11 08:01:02.381] - main.cpp:275 - ConnectorId:2; Event:ConnectorDisconnect; CurrentStatus:IDLE
[2024/01/11 08:01:02:6371] N: __lws_lc_untag:  -- [wsicli|0|WS/h1/default/192.168.10.10] (0) 20.713s
[2024/01/11 08:01:04:3552] N: __lws_lc_tag:  ++ [wsicli|1|WS/h1/default/192.168.10.10] (1)
[[ INFO  ][ - [2024-01-11 08:01:04.378] - ChargePoint.cpp:924 - Connected to Central System
[[  COM  ][ - [2024-01-11 08:01:04.413] - ChargePoint.cpp:989 - TX : [2, "1849143064", "BootNotification", {"chargeBoxSerialNumber":"","chargePointModel":"EA_DC_CHARGE_STATIO","chargePointSerialNumber":"23859016","chargePointVendor":"","firmwareVersion":"1.0.0","iccid":"","imsi":"","meterSerialNumber":""}]
[[  COM  ][ - [2024-01-11 08:01:04.540] - ChargePoint.cpp:982 - RX : [3,"1849143064",{"status":"Accepted","currentTime":"2024-01-11T00:01:07.630Z","interval":60}]
[[  COM  ][ - [2024-01-11 08:01:04.669] - ChargePoint.cpp:989 - TX : [2, "1849143065", "StatusNotification", {"connectorId":0,"errorCode":"NoError","status":"Available","timestamp":"2024-01-11T00:00:41Z"}]
[[  COM  ][ - [2024-01-11 08:01:04.754] - ChargePoint.cpp:982 - RX : [3,"1849143065",{}]
[[  COM  ][ - [2024-01-11 08:01:04.850] - ChargePoint.cpp:989 - TX : [2, "1849143066", "StatusNotification", {"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2024-01-11T00:00:41Z"}]
[[  COM  ][ - [2024-01-11 08:01:04.926] - ChargePoint.cpp:982 - RX : [3,"1849143066",{}]
[[  COM  ][ - [2024-01-11 08:01:05.015] - ChargePoint.cpp:989 - TX : [2, "1849143067", "StatusNotification", {"connectorId":2,"errorCode":"NoError","status":"Available","timestamp":"2024-01-11T00:00:41Z"}]
[[  COM  ][ - [2024-01-11 08:01:05.086] - ChargePoint.cpp:982 - RX : [3,"1849143067",{}]
[[ INFO  ][ - [2024-01-11 08:01:05.124] - StatusManager.cpp:495 - Registration status : Accepted
[[ INFO  ][ - [2024-01-11 08:01:07.039] - MeterValuesManager.cpp:319 - Configure clock aligned meter values : interval in seconds = 30
[[ INFO  ][ - [2024-01-11 08:01:07.062] - MeterValuesManager.cpp:325 - Thu Jan 11 08:01:30 2024
[[  COM  ][ - [2024-01-11 08:01:21.009] - ChargePoint.cpp:982 - RX : [2,"1704902482252","ChangeConfiguration",{"key":"LocalPreAuthorize","value":"false"}]
[[  COM  ][ - [2024-01-11 08:01:21.064] - ChargePoint.cpp:989 - TX : [3, "1704902482252", {"status":"Accepted"}]
[[  COM  ][ - [2024-01-11 08:01:21.149] - ChargePoint.cpp:982 - RX : [2,"1704902482393","GetConfiguration",{"key":["AuthorizeRemoteTxRequests"]}]
[[  COM  ][ - [2024-01-11 08:01:21.184] - ChargePoint.cpp:989 - TX : [3, "1704902482393", {"configurationKey":[{"key":"AuthorizeRemoteTxRequests","readonly":true,"value":"false"}],"unknownKey":[]}]
[[ INFO  ][ - [2024-01-11 08:01:26.923] - main.cpp:275 - ConnectorId:1; Event:ConnectorDisconnect; CurrentStatus:IDLE
[[  COM  ][ - [2024-01-11 08:01:27.733] - ChargePoint.cpp:982 - RX : [2,"1704902488974","RemoteStartTransaction",{"connectorId":2,"idTag":"56727548615757"}]
[[ INFO  ][ - [2024-01-11 08:01:27.769] - TransactionManager.cpp:292 - Remote start transaction requested : connector = 2 - idTag = 56727548615757
[[ INFO  ][ - [2024-01-11 08:01:27.819] - TransactionManager.cpp:336 - Remote start transaction Accepted : connector = 2
[[ INFO  ][ - [2024-01-11 08:01:27.820] - main.cpp:424 - ConnectorId:2; Event:RemoteStartPending; CurrentStatus:IDLE
[[  COM  ][ - [2024-01-11 08:01:27.848] - ChargePoint.cpp:989 - TX : [3, "1704902488974", {"status":"Accepted"}]
[[ DEBUG ][ - [2024-01-11 08:01:28.001] - Connectors.cpp:303 - Connector 2 updated in database
[[ INFO  ][ - [2024-01-11 08:01:28.046] - StatusManager.cpp:167 - Connector 2 : Preparing
[[  COM  ][ - [2024-01-11 08:01:28.205] - ChargePoint.cpp:989 - TX : [2, "1849143068", "StatusNotification", {"connectorId":2,"errorCode":"NoError","status":"Preparing","timestamp":"2024-01-11T00:01:27Z"}]
[[  COM  ][ - [2024-01-11 08:01:28.304] - ChargePoint.cpp:982 - RX : [3,"1849143068",{}]
[[ DEBUG ][ - [2024-01-11 08:01:30.086] - MeterValuesManager.cpp:361 - Clock aligned meter values : Current.Import,Energy.Active.Import.Register,Power.Active.Import,Voltage.L1-L2,Voltage.L2-L3,Voltage.L3-L1,SoC,Temperature
[[  COM  ][ - [2024-01-11 08:01:30.146] - ChargePoint.cpp:989 - TX : [2, "1849143069", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:01:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"401","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"402","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:01:31.735] - ChargePoint.cpp:982 - RX : [4,"1849143069","InternalError","An internal error occurred and the receiver was not able to process the requested Action successfully",{}]
[[  COM  ][ - [2024-01-11 08:01:31.770] - ChargePoint.cpp:989 - TX : [2, "1849143070", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:01:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ DEBUG ][ - [2024-01-11 08:01:36.799] - RequestFifo.cpp:44 - Transaction related request FIFO : pushing MeterValues request
[[ DEBUG ][ - [2024-01-11 08:01:36.842] - RequestFifoManager.cpp:94 - Request failed, next retry in 5second(s)
[[ DEBUG ][ - [2024-01-11 08:01:41.865] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 0/3
[[  COM  ][ - [2024-01-11 08:01:41.903] - ChargePoint.cpp:989 - TX : [2, "1849143071", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:01:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:01:42.001] - ChargePoint.cpp:982 - RX : [3,"1849143071",{}]
[[ DEBUG ][ - [2024-01-11 08:01:42.067] - RequestFifoManager.cpp:218 - Request succeeded
[[ DEBUG ][ - [2024-01-11 08:01:42.109] - RequestFifo.cpp:101 - Transaction related request FIFO : poping MeterValues request
[[  COM  ][ - [2024-01-11 08:01:44.972] - ChargePoint.cpp:982 - RX : [2,"1704902506216","ChangeConfiguration",{"key":"LocalPreAuthorize","value":"false"}]
[[  COM  ][ - [2024-01-11 08:01:45.015] - ChargePoint.cpp:989 - TX : [3, "1704902506216", {"status":"Accepted"}]
[[  COM  ][ - [2024-01-11 08:01:45.094] - ChargePoint.cpp:982 - RX : [2,"1704902506336","GetConfiguration",{"key":["AuthorizeRemoteTxRequests"]}]
[[  COM  ][ - [2024-01-11 08:01:45.145] - ChargePoint.cpp:989 - TX : [3, "1704902506336", {"configurationKey":[{"key":"AuthorizeRemoteTxRequests","readonly":true,"value":"false"}],"unknownKey":[]}]
[[  COM  ][ - [2024-01-11 08:01:52.119] - ChargePoint.cpp:982 - RX : [2,"1704902513362","RemoteStartTransaction",{"connectorId":2,"idTag":"56727548615757"}]
[[ INFO  ][ - [2024-01-11 08:01:52.159] - TransactionManager.cpp:292 - Remote start transaction requested : connector = 2 - idTag = 56727548615757
[[ INFO  ][ - [2024-01-11 08:01:52.209] - TransactionManager.cpp:336 - Remote start transaction Accepted : connector = 2
[[ INFO  ][ - [2024-01-11 08:01:52.210] - main.cpp:424 - ConnectorId:2; Event:RemoteStartPending; CurrentStatus:PREPARE_AUTHED
[[  COM  ][ - [2024-01-11 08:01:52.235] - ChargePoint.cpp:989 - TX : [3, "1704902513362", {"status":"Accepted"}]
[[ DEBUG ][ - [2024-01-11 08:02:00.086] - MeterValuesManager.cpp:361 - Clock aligned meter values : Current.Import,Energy.Active.Import.Register,Power.Active.Import,Voltage.L1-L2,Voltage.L2-L3,Voltage.L3-L1,SoC,Temperature
[[  COM  ][ - [2024-01-11 08:02:00.134] - ChargePoint.cpp:989 - TX : [2, "1849143072", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:02:00Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:02:01.752] - ChargePoint.cpp:982 - RX : [4,"1849143072","InternalError","An internal error occurred and the receiver was not able to process the requested Action successfully",{}]
[[  COM  ][ - [2024-01-11 08:02:01.793] - ChargePoint.cpp:989 - TX : [2, "1849143073", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:02:00Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ DEBUG ][ - [2024-01-11 08:02:06.819] - RequestFifo.cpp:44 - Transaction related request FIFO : pushing MeterValues request
[[ DEBUG ][ - [2024-01-11 08:02:06.864] - RequestFifoManager.cpp:94 - Request failed, next retry in 5second(s)
[[ DEBUG ][ - [2024-01-11 08:02:11.888] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 0/3
[[  COM  ][ - [2024-01-11 08:02:11.925] - ChargePoint.cpp:989 - TX : [2, "1849143074", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:02:00Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:02:12.001] - ChargePoint.cpp:982 - RX : [3,"1849143074",{}]
[[ DEBUG ][ - [2024-01-11 08:02:12.036] - RequestFifoManager.cpp:218 - Request succeeded
[[ DEBUG ][ - [2024-01-11 08:02:12.061] - RequestFifo.cpp:101 - Transaction related request FIFO : poping MeterValues request
[[ DEBUG ][ - [2024-01-11 08:02:30.086] - MeterValuesManager.cpp:361 - Clock aligned meter values : Current.Import,Energy.Active.Import.Register,Power.Active.Import,Voltage.L1-L2,Voltage.L2-L3,Voltage.L3-L1,SoC,Temperature
[[  COM  ][ - [2024-01-11 08:02:30.147] - ChargePoint.cpp:989 - TX : [2, "1849143075", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:02:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:02:30.269] - ChargePoint.cpp:982 - RX : [3,"1849143075",{}]
[[  COM  ][ - [2024-01-11 08:02:30.336] - ChargePoint.cpp:989 - TX : [2, "1849143076", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:02:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:02:30.436] - ChargePoint.cpp:982 - RX : [3,"1849143076",{}]
[[  COM  ][ - [2024-01-11 08:02:39.069] - ChargePoint.cpp:982 - RX : [2,"1704902560317","GetConfiguration",{"key":["AuthorizeRemoteTxRequests"]}]
[[  COM  ][ - [2024-01-11 08:02:39.113] - ChargePoint.cpp:989 - TX : [3, "1704902560317", {"configurationKey":[{"key":"AuthorizeRemoteTxRequests","readonly":true,"value":"false"}],"unknownKey":[]}]
[[ DEBUG ][ - [2024-01-11 08:02:52.399] - Connectors.cpp:303 - Connector 2 updated in database
[[ INFO  ][ - [2024-01-11 08:02:52.435] - StatusManager.cpp:167 - Connector 2 : Available
[[  COM  ][ - [2024-01-11 08:02:52.506] - ChargePoint.cpp:989 - TX : [2, "1849143077", "StatusNotification", {"connectorId":2,"errorCode":"NoError","status":"Available","timestamp":"2024-01-11T00:02:52Z"}]
[[  COM  ][ - [2024-01-11 08:02:52.575] - ChargePoint.cpp:982 - RX : [3,"1849143077",{}]
[[ INFO  ][ - [2024-01-11 08:02:55.453] - main.cpp:200 - ConnectorId:1; Event:ConnectorConnect; CurrentStatus:IDLE
[[ DEBUG ][ - [2024-01-11 08:02:55.530] - Connectors.cpp:303 - Connector 1 updated in database
[[ INFO  ][ - [2024-01-11 08:02:55.553] - StatusManager.cpp:167 - Connector 1 : Preparing
[[  COM  ][ - [2024-01-11 08:02:55.606] - ChargePoint.cpp:982 - RX : [2,"1704902576853","RemoteStartTransaction",{"connectorId":2,"idTag":"56727548615757"}]
[[  COM  ][ - [2024-01-11 08:02:55.629] - ChargePoint.cpp:989 - TX : [2, "1849143078", "StatusNotification", {"connectorId":1,"errorCode":"NoError","status":"Preparing","timestamp":"2024-01-11T00:02:55Z"}]
[[ INFO  ][ - [2024-01-11 08:02:55.659] - TransactionManager.cpp:292 - Remote start transaction requested : connector = 2 - idTag = 56727548615757
[[  COM  ][ - [2024-01-11 08:02:55.731] - ChargePoint.cpp:982 - RX : [3,"1849143078",{}]
[[ INFO  ][ - [2024-01-11 08:02:55.736] - TransactionManager.cpp:336 - Remote start transaction Accepted : connector = 2
[[ INFO  ][ - [2024-01-11 08:02:55.788] - main.cpp:424 - ConnectorId:2; Event:RemoteStartPending; CurrentStatus:IDLE
[[  COM  ][ - [2024-01-11 08:02:55.792] - ChargePoint.cpp:989 - TX : [3, "1704902576853", {"status":"Accepted"}]
[[ DEBUG ][ - [2024-01-11 08:02:56.032] - Connectors.cpp:303 - Connector 2 updated in database
[[ INFO  ][ - [2024-01-11 08:02:56.055] - StatusManager.cpp:167 - Connector 2 : Preparing
[[  COM  ][ - [2024-01-11 08:02:56.256] - ChargePoint.cpp:989 - TX : [2, "1849143079", "StatusNotification", {"connectorId":2,"errorCode":"NoError","status":"Preparing","timestamp":"2024-01-11T00:02:56Z"}]
[[ DEBUG ][ - [2024-01-11 08:03:00.086] - MeterValuesManager.cpp:361 - Clock aligned meter values : Current.Import,Energy.Active.Import.Register,Power.Active.Import,Voltage.L1-L2,Voltage.L2-L3,Voltage.L3-L1,SoC,Temperature
[[  COM  ][ - [2024-01-11 08:03:01.339] - ChargePoint.cpp:989 - TX : [2, "1849143080", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:03:00Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:03:01.446] - ChargePoint.cpp:982 - RX : [3,"1849143080",{}]
[[  COM  ][ - [2024-01-11 08:03:01.528] - ChargePoint.cpp:989 - TX : [2, "1849143081", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:03:00Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[  COM  ][ - [2024-01-11 08:03:01.630] - ChargePoint.cpp:982 - RX : [3,"1849143081",{}]
[[ ERROR ][ - [2024-01-11 08:03:19.210] - ChargePoint.cpp:953 - Connection lost with Central System
[2024/01/11 08:03:19:2957] N: __lws_lc_untag:  -- [wsicli|1|WS/h1/default/192.168.10.10] (0) 2.218min
[2024/01/11 08:03:20:4003] N: __lws_lc_tag:  ++ [wsicli|2|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:20:4047] N: [wsicli|2|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:20:4051] N: __lws_lc_untag:  -- [wsicli|2|WS/h1/default/192.168.10.10] (0) 4.809ms
[2024/01/11 08:03:21:6037] N: __lws_lc_tag:  ++ [wsicli|3|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:21:6075] N: [wsicli|3|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:21:6079] N: __lws_lc_untag:  -- [wsicli|3|WS/h1/default/192.168.10.10] (0) 4.260ms
[2024/01/11 08:03:22:7965] N: __lws_lc_tag:  ++ [wsicli|4|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:22:8020] N: [wsicli|4|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:22:8024] N: __lws_lc_untag:  -- [wsicli|4|WS/h1/default/192.168.10.10] (0) 5.952ms
[2024/01/11 08:03:23:9299] N: __lws_lc_tag:  ++ [wsicli|5|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:23:9334] N: [wsicli|5|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:23:9338] N: __lws_lc_untag:  -- [wsicli|5|WS/h1/default/192.168.10.10] (0) 3.889ms
[2024/01/11 08:03:25:0859] N: __lws_lc_tag:  ++ [wsicli|6|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:25:0895] N: [wsicli|6|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:25:0899] N: __lws_lc_untag:  -- [wsicli|6|WS/h1/default/192.168.10.10] (0) 3.962ms
[[ INFO  ][ - [2024-01-11 08:03:25.546] - main.cpp:275 - ConnectorId:1; Event:ConnectorDisconnect; CurrentStatus:PREPARE_CONNECTED
[[ DEBUG ][ - [2024-01-11 08:03:25.606] - Connectors.cpp:303 - Connector 1 updated in database
[[ INFO  ][ - [2024-01-11 08:03:25.628] - StatusManager.cpp:167 - Connector 1 : Available
[2024/01/11 08:03:26:1319] N: __lws_lc_tag:  ++ [wsicli|7|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:26:1386] N: [wsicli|7|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:26:1390] N: __lws_lc_untag:  -- [wsicli|7|WS/h1/default/192.168.10.10] (0) 7.127ms
[2024/01/11 08:03:27:2285] N: __lws_lc_tag:  ++ [wsicli|8|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:27:2333] N: [wsicli|8|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:27:2338] N: __lws_lc_untag:  -- [wsicli|8|WS/h1/default/192.168.10.10] (0) 5.224ms
[2024/01/11 08:03:28:3533] N: __lws_lc_tag:  ++ [wsicli|9|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:28:3575] N: [wsicli|9|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:28:3579] N: __lws_lc_untag:  -- [wsicli|9|WS/h1/default/192.168.10.10] (0) 4.674ms
[2024/01/11 08:03:29:4813] N: __lws_lc_tag:  ++ [wsicli|a|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:29:4866] N: [wsicli|a|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:29:4870] N: __lws_lc_untag:  -- [wsicli|a|WS/h1/default/192.168.10.10] (0) 5.683ms
[[ DEBUG ][ - [2024-01-11 08:03:30.086] - MeterValuesManager.cpp:361 - Clock aligned meter values : Current.Import,Energy.Active.Import.Register,Power.Active.Import,Voltage.L1-L2,Voltage.L2-L3,Voltage.L3-L1,SoC,Temperature
[[ DEBUG ][ - [2024-01-11 08:03:30.136] - RequestFifo.cpp:44 - Transaction related request FIFO : pushing MeterValues request
[[ DEBUG ][ - [2024-01-11 08:03:30.203] - RequestFifo.cpp:44 - Transaction related request FIFO : pushing MeterValues request
[2024/01/11 08:03:30:5374] N: __lws_lc_tag:  ++ [wsicli|b|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:30:5416] N: [wsicli|b|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:30:5422] N: __lws_lc_untag:  -- [wsicli|b|WS/h1/default/192.168.10.10] (0) 4.706ms
[2024/01/11 08:03:31:5856] N: __lws_lc_tag:  ++ [wsicli|c|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:31:5888] N: [wsicli|c|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:31:5893] N: __lws_lc_untag:  -- [wsicli|c|WS/h1/default/192.168.10.10] (0) 3.705ms
[2024/01/11 08:03:32:6297] N: __lws_lc_tag:  ++ [wsicli|d|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:32:6326] N: [wsicli|d|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:32:6331] N: __lws_lc_untag:  -- [wsicli|d|WS/h1/default/192.168.10.10] (0) 3.349ms
[2024/01/11 08:03:33:7526] N: __lws_lc_tag:  ++ [wsicli|e|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:33:7571] N: [wsicli|e|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:33:7576] N: __lws_lc_untag:  -- [wsicli|e|WS/h1/default/192.168.10.10] (0) 4.948ms
[2024/01/11 08:03:34:9036] N: __lws_lc_tag:  ++ [wsicli|f|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:34:9078] N: [wsicli|f|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 9 says e 111
[2024/01/11 08:03:34:9082] N: __lws_lc_untag:  -- [wsicli|f|WS/h1/default/192.168.10.10] (0) 4.626ms
[2024/01/11 08:03:35:9687] N: __lws_lc_tag:  ++ [wsicli|10|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:35:9732] N: [wsicli|10|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:35:9737] N: __lws_lc_untag:  -- [wsicli|10|WS/h1/default/192.168.10.10] (0) 5.001ms
[2024/01/11 08:03:37:0820] N: __lws_lc_tag:  ++ [wsicli|11|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:37:0863] N: [wsicli|11|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:37:0868] N: __lws_lc_untag:  -- [wsicli|11|WS/h1/default/192.168.10.10] (0) 4.738ms
[2024/01/11 08:03:38:1802] N: __lws_lc_tag:  ++ [wsicli|12|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:38:1847] N: [wsicli|12|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:38:1852] N: __lws_lc_untag:  -- [wsicli|12|WS/h1/default/192.168.10.10] (0) 4.974ms
[2024/01/11 08:03:39:2746] N: __lws_lc_tag:  ++ [wsicli|13|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:39:2802] N: [wsicli|13|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:39:2808] N: __lws_lc_untag:  -- [wsicli|13|WS/h1/default/192.168.10.10] (0) 6.169ms
[2024/01/11 08:03:40:3523] N: __lws_lc_tag:  ++ [wsicli|14|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:40:3566] N: [wsicli|14|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:40:3653] N: __lws_lc_untag:  -- [wsicli|14|WS/h1/default/192.168.10.10] (0) 12.995ms
[2024/01/11 08:03:41:5158] N: __lws_lc_tag:  ++ [wsicli|15|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:41:5207] N: [wsicli|15|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:41:5212] N: __lws_lc_untag:  -- [wsicli|15|WS/h1/default/192.168.10.10] (0) 5.346ms
[2024/01/11 08:03:42:5235] N: __lws_lc_tag:  ++ [wsicli|16|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:42:5271] N: [wsicli|16|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:42:5275] N: __lws_lc_untag:  -- [wsicli|16|WS/h1/default/192.168.10.10] (0) 3.953ms
[2024/01/11 08:03:43:5889] N: __lws_lc_tag:  ++ [wsicli|17|WS/h1/default/192.168.10.10] (1)
[2024/01/11 08:03:43:5950] N: [wsicli|17|WS/h1/default/192.168.10.10]: lws_client_connect_check: getsockopt fd 8 says e 111
[2024/01/11 08:03:43:5954] N: __lws_lc_untag:  -- [wsicli|17|WS/h1/default/192.168.10.10] (0) 6.518ms
[2024/01/11 08:03:44:6350] N: __lws_lc_tag:  ++ [wsicli|18|WS/h1/default/192.168.10.10] (1)
[[ INFO  ][ - [2024-01-11 08:03:44.657] - ChargePoint.cpp:924 - Connected to Central System
[[  COM  ][ - [2024-01-11 08:03:44.744] - ChargePoint.cpp:989 - TX : [2, "1849143082", "StatusNotification", {"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2024-01-11T00:03:25Z"}]
[[  COM  ][ - [2024-01-11 08:03:49.823] - ChargePoint.cpp:989 - TX : [2, "1849143083", "StatusNotification", {"connectorId":2,"errorCode":"NoError","status":"Preparing","timestamp":"2024-01-11T00:02:56Z"}]
[[ INFO  ][ - [2024-01-11 08:03:54.844] - RequestFifoManager.cpp:80 - Restart transaction related FIFO processing
[[ DEBUG ][ - [2024-01-11 08:03:54.876] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 0/3
[[  COM  ][ - [2024-01-11 08:03:54.910] - ChargePoint.cpp:989 - TX : [2, "1849143084", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:03:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ ERROR ][ - [2024-01-11 08:03:54.987] - ChargePoint.cpp:953 - Connection lost with Central System
[2024/01/11 08:03:55:0928] N: __lws_lc_untag:  -- [wsicli|18|WS/h1/default/192.168.10.10] (0) 10.457s
[[ DEBUG ][ - [2024-01-11 08:03:55.936] - Connectors.cpp:303 - Connector 2 updated in database
[[ INFO  ][ - [2024-01-11 08:03:55.958] - StatusManager.cpp:167 - Connector 2 : Available
[2024/01/11 08:03:56:2556] N: __lws_lc_tag:  ++ [wsicli|19|WS/h1/default/192.168.10.10] (1)
[[ INFO  ][ - [2024-01-11 08:03:56.286] - ChargePoint.cpp:924 - Connected to Central System
[[ DEBUG ][ - [2024-01-11 08:03:59.960] - RequestFifoManager.cpp:240 - Request failed, next retry in 5second(s)
[[  COM  ][ - [2024-01-11 08:03:59.962] - ChargePoint.cpp:989 - TX : [2, "1849143085", "StatusNotification", {"connectorId":1,"errorCode":"NoError","status":"Available","timestamp":"2024-01-11T00:03:25Z"}]
[[ DEBUG ][ - [2024-01-11 08:04:00.086] - MeterValuesManager.cpp:361 - Clock aligned meter values : Current.Import,Energy.Active.Import.Register,Power.Active.Import,Voltage.L1-L2,Voltage.L2-L3,Voltage.L3-L1,SoC,Temperature
[[ DEBUG ][ - [2024-01-11 08:04:00.115] - RequestFifo.cpp:44 - Transaction related request FIFO : pushing MeterValues request
[[ DEBUG ][ - [2024-01-11 08:04:00.173] - RequestFifo.cpp:44 - Transaction related request FIFO : pushing MeterValues request
[[ DEBUG ][ - [2024-01-11 08:04:04.997] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 1/3
[[ INFO  ][ - [2024-01-11 08:04:05.060] - RequestFifoManager.cpp:80 - Restart transaction related FIFO processing
[[  COM  ][ - [2024-01-11 08:04:05.062] - ChargePoint.cpp:989 - TX : [2, "1849143086", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:03:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ DEBUG ][ - [2024-01-11 08:04:05.092] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 1/3
[[  COM  ][ - [2024-01-11 08:04:05.265] - ChargePoint.cpp:982 - RX : [3,"1849143082",{}]
[[  COM  ][ - [2024-01-11 08:04:05.325] - ChargePoint.cpp:982 - RX : [3,"1849143083",{}]
[[  COM  ][ - [2024-01-11 08:04:05.361] - ChargePoint.cpp:982 - RX : [3,"1849143084",{}]
[[  COM  ][ - [2024-01-11 08:04:05.414] - ChargePoint.cpp:982 - RX : [3,"1849143085",{}]
[[  COM  ][ - [2024-01-11 08:04:05.454] - ChargePoint.cpp:982 - RX : [3,"1849143086",{}]
[[ DEBUG ][ - [2024-01-11 08:04:05.477] - RequestFifoManager.cpp:218 - Request succeeded
[[  COM  ][ - [2024-01-11 08:04:05.482] - ChargePoint.cpp:989 - TX : [2, "1849143087", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:03:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"400","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ DEBUG ][ - [2024-01-11 08:04:05.512] - RequestFifo.cpp:101 - Transaction related request FIFO : poping MeterValues request
[[ DEBUG ][ - [2024-01-11 08:04:05.572] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 0/3
[[  COM  ][ - [2024-01-11 08:04:05.586] - ChargePoint.cpp:982 - RX : [3,"1849143087",{}]
[[ DEBUG ][ - [2024-01-11 08:04:05.631] - RequestFifoManager.cpp:218 - Request succeeded
[[  COM  ][ - [2024-01-11 08:04:05.638] - ChargePoint.cpp:989 - TX : [2, "1849143088", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:03:30Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ DEBUG ][ - [2024-01-11 08:04:05.668] - RequestFifo.cpp:101 - Transaction related request FIFO : poping MeterValues request
[[ DEBUG ][ - [2024-01-11 08:04:05.733] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 0/3
[[  COM  ][ - [2024-01-11 08:04:05.742] - ChargePoint.cpp:982 - RX : [3,"1849143088",{}]
[[ DEBUG ][ - [2024-01-11 08:04:05.784] - RequestFifoManager.cpp:218 - Request succeeded
[[  COM  ][ - [2024-01-11 08:04:05.792] - ChargePoint.cpp:989 - TX : [2, "1849143089", "MeterValues", {"connectorId":1,"meterValue":[{"timestamp":"2024-01-11T00:04:00Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"258.140","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"399","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"60","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"15","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ DEBUG ][ - [2024-01-11 08:04:05.822] - RequestFifo.cpp:101 - Transaction related request FIFO : poping MeterValues request
[[ DEBUG ][ - [2024-01-11 08:04:05.889] - RequestFifoManager.cpp:116 - Request FIFO processing MeterValues retries : 0/3
[[  COM  ][ - [2024-01-11 08:04:05.899] - ChargePoint.cpp:982 - RX : [3,"1849143089",{}]
[[ DEBUG ][ - [2024-01-11 08:04:05.940] - RequestFifoManager.cpp:218 - Request succeeded
[[  COM  ][ - [2024-01-11 08:04:05.942] - ChargePoint.cpp:989 - TX : [2, "1849143090", "MeterValues", {"connectorId":2,"meterValue":[{"timestamp":"2024-01-11T00:04:00Z","sampledValue":[{"value":"0.0","context":"Sample.Clock","format":"Raw","measurand":"Current.Import","unit":"A"},{"value":"267.630","context":"Sample.Clock","format":"Raw","measurand":"Energy.Active.Import.Register","unit":"kWh"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Power.Active.Import","unit":"W"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L1-L2","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L2-L3","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"Voltage","phase":"L3-L1","unit":"V"},{"value":"0","context":"Sample.Clock","format":"Raw","measurand":"SoC","unit":"Percent"},{"value":"14","context":"Sample.Clock","format":"Raw","measurand":"Temperature","unit":"Celsius"}]}]}]
[[ DEBUG ][ - [2024-01-11 08:04:05.972] - RequestFifo.cpp:101 - Transaction related request FIFO : poping MeterValues request
[[  COM  ][ - [2024-01-11 08:04:06.049] - ChargePoint.cpp:982 - RX : [3,"1849143090",{}]
[[ DEBUG ][ - [2024-01-11 08:04:06.076] - RequestFifoManager.cpp:218 - Request succeeded
[[ DEBUG ][ - [2024-01-11 08:04:06.103] - RequestFifo.cpp:101 - Transaction related request FIFO : poping  request
Habbus commented

Hi,

I have not extensively read through your log messages, but we have experienced issues with processing cached messages as well. As soon as backend connection was restored the requestfifo will be emptied, and then we experienced constant crashing.

In the discussion section I posted something about the memory allocator used by rapidjson: #165

You can try to follow the steps as described there (using only the CrtAllocator instead of the MemoryPoolAllocator), that fixed it for us. Apparently the memory pool allocator can cause problems. I'm still planning to make a clean solution so one can choose which allocator to use from the cmake options, but until then you will have to try it manually.

Using the CrtAllocator (basically just a wrapper around your regular malloc and free) should be perfectly fine, at least on a linux system. We have been running on an armv7 board with our own yocto-made distribution on it.
Let me know if this helps!

Habbus commented

Hi, an option was added to use the CrtAllocator. Try setting this option to ON

open-ocpp/CMakeLists_Options.txt

Line 30 in 09ba2af

option(USE_CRT_ALLOC_FOR_RAPIDJSON "Use the CrtAllocator for Rapidjson instead of the MemoryPoolAllocator" OFF)

Might resolve your problem.