deduplicate new operations received on c8y/devicecontrol/notifications #3403
Description
Is your feature improvement request related to a problem? Please describe.
Whilst running various system tests, it's been observed that the same Cumulocity operation can be sent multiple times from Cumulocity from the c8y/devicecontrol/notifications topic.
It is unclear whether the server is sending multiple messages, or it is a by-product of a QoS 1 setting either from the bridge to the cloud, or from the tedge-mapper to the local bridge.
Since the operation is essentially received twice by the tedge-mapper, it results in processing the same operation twice which is very unexpected for users and can be potentially harmful if the user is doing an action which is not idempotent.
It was previous suspected that the duplicate message was caused by the tedge-mapper c8y sending a 500 SmartREST message however this does not seem to be the case as shown in the first result in the Additional context section.
Describe the solution you'd like
Implement an operation de-duplication mechanism (not relying on MQTT) to prevent the same operation from being processed twice.
We could potentially just do an in-memory store as the duplicate operations are received within a few seconds of each other, however a file-based cache might be a more robust approach but @didier-wenzek you guide the solution here.
Describe alternatives you've considered
Additional context
The following are examples where the same operation has been received on the c8y/devicecontrol/notifications local MQTT broker topic (observed by the mqtt-logger process which runs during the system test).
Test: Run custom operation with workflow execution
The following operation appears twice in the mqtt-logger output, and it shows that the duplicate operation triggers the workflow again.
c8y/devicecontrol/notifications {"delivery":{"log":[],"time":"2025-02-14T13:32:26.380Z","status":"PENDING"},"agentId":"3344163335","creationTime":"2025-02-14T13:32:26.356Z","deviceId":"3344163335","id":"44160776","status":"PENDING","description":"take a picture","c8y_TakePicture":{"parameters":{"duration":"5s","quality":"HD"}},"externalSource":{"externalId":"TST_multiply_crispy_balcony","type":"c8y_Serial"}}
2025-02-14T13:32:26.943460Z c8y/devicecontrol/notifications {"delivery":{"log":[],"time":"2025-02-14T13:32:26.380Z","status":"PENDING"},"agentId":"3344163335","creationTime":"2025-02-14T13:32:26.356Z","deviceId":"3344163335","id":"44160776","status":"PENDING","description":"take a picture","c8y_TakePicture":{"parameters":{"duration":"5s","quality":"HD"}},"externalSource":{"externalId":"TST_multiply_crispy_balcony","type":"c8y_Serial"}}
2025-02-14T13:32:26.943923Z te/device/main///cmd/take_picture/c8y-mapper-44160776 {"c8y-mapper":{"on_fragment":"c8y_TakePicture","output":null},"duration":"5s","quality":"HD","status":"init"}
2025-02-14T13:32:26.953256Z te/device/main///cmd/take_picture/c8y-mapper-44160776 {"@version":"bfad95f8b7125200d66dd0f0ef4d619e5c65c0a1a8b29101563d2a8019f48f7d","c8y-mapper":{"on_fragment":"c8y_TakePicture","output":null},"duration":"5s","logPath":"/var/log/tedge/agent/workflow-take_picture-c8y-mapper-44160776.log","quality":"HD","status":"executing"}
2025-02-14T13:32:26.956937Z te/device/main///cmd/take_picture/c8y-mapper-44160776 {"@version":"bfad95f8b7125200d66dd0f0ef4d619e5c65c0a1a8b29101563d2a8019f48f7d","c8y-mapper":{"on_fragment":"c8y_TakePicture","output":null},"duration":"5s","logPath":"/var/log/tedge/agent/workflow-take_picture-c8y-mapper-44160776.log","quality":"HD","something":"5s HD","status":"successful"}
2025-02-14T13:32:27.025854Z c8y/s/us 504,44160776
2025-02-14T13:32:27.025878Z c8y/s/us 506,44160776
2025-02-14T13:32:27.026042Z te/device/main///cmd/take_picture/c8y-mapper-44160776
2025-02-14T13:32:27.039833Z c8y/s/dat 71,<redacted>
2025-02-14T13:32:27.055981Z c8y/devicecontrol/notifications {"delivery":{"log":[{"time":"2025-02-14T13:32:26.380Z","status":"PENDING"},{"time":"2025-02-14T13:32:26.394Z","status":"SEND"}],"time":"2025-02-14T13:32:26.968Z","status":"PENDING"},"agentId":"3344163335","creationTime":"2025-02-14T13:32:26.356Z","deviceId":"3344163335","id":"44160776","status":"PENDING","description":"take a picture","c8y_TakePicture":{"parameters":{"duration":"5s","quality":"HD"}},"externalSource":{"externalId":"TST_multiply_crispy_balcony","type":"c8y_Serial"}}
2025-02-14T13:32:27.109834Z te/device/main///cmd/take_picture/c8y-mapper-44160776 {"c8y-mapper":{"on_fragment":"c8y_TakePicture","output":null},"duration":"5s","quality":"HD","status":"init"}
2025-02-14T13:32:27.120133Z te/device/main///cmd/take_picture/c8y-mapper-44160776 {"@version":"bfad95f8b7125200d66dd0f0ef4d619e5c65c0a1a8b29101563d2a8019f48f7d","c8y-mapper":{"on_fragment":"c8y_TakePicture","output":null},"duration":"5s","logPath":"/var/log/tedge/agent/workflow-take_picture-c8y-mapper-44160776.log","quality":"HD","status":"executing"}
2025-02-14T13:32:27.124580Z te/device/main///cmd/take_picture/c8y-mapper-44160776 {"@version":"bfad95f8b7125200d66dd0f0ef4d619e5c65c0a1a8b29101563d2a8019f48f7d","c8y-mapper":{"on_fragment":"c8y_TakePicture","output":null},"duration":"5s","logPath":"/var/log/tedge/agent/workflow-take_picture-c8y-mapper-44160776.log","quality":"HD","something":"5s HD","status":"successful"}
2025-02-14T13:32:27.206446Z te/device/main///cmd/software_list/c8y-mapper-2025-02-14T13:32:25.837243932Z
Test: Cumulocity.Custom Operation.Custom Operation Command.Run shell custom operation for main device and publish the status
Log output take from the existing flaky system test ticket: #3399
2025-02-13T18:09:30.731093Z c8y/s/us 114,c8y_Command,c8y_DeviceProfile,c8y_DownloadConfigFile,c8y_LogfileRequest,c8y_RemoteAccessConnect,c8y_Restart,c8y_SoftwareUpdate,c8y_UploadConfigFile
2025-02-13T18:09:30.796371Z te/device/main/service/c8y-firmware-plugin {"@parent":"device/main//","@type":"service","type":"service"}
2025-02-13T18:09:30.796439Z te/device/main/service/c8y-firmware-plugin/status/health {"pid":697,"status":"up","time":1739470170.7517972}
2025-02-13T18:09:30.796591Z c8y/s/us 500
2025-02-13T18:09:30.796725Z c8y/s/us 102,TST_draw_parallel_report:device:main:service:c8y-firmware-plugin,service,c8y-firmware-plugin,up
2025-02-13T18:09:30.797070Z c8y/s/us 102,TST_draw_parallel_report:device:main:service:c8y-firmware-plugin,service,c8y-firmware-plugin,up
2025-02-13T18:09:30.817578Z c8y/devicecontrol/notifications {"delivery":{"log":[],"time":"2025-02-13T18:09:30.757Z","status":"PENDING"},"agentId":"5616033475","creationTime":"2025-02-13T18:09:30.734Z","deviceId":"5616033475","id":"16031595","status":"PENDING","c8y_Command":{"text":"echo helloworld1"},"description":"echo helloworld","externalSource":{"externalId":"TST_draw_parallel_report","type":"c8y_Serial"}}
2025-02-13T18:09:30.817881Z c8y/s/ds 511,TST_draw_parallel_report,echo helloworld1
2025-02-13T18:09:30.883558Z c8y/s/us 504,16031595
2025-02-13T18:09:30.884274Z c8y/s/us 506,16031595,"helloworld1
"
2025-02-13T18:09:30.912885Z c8y/devicecontrol/notifications {"delivery":{"log":[{"time":"2025-02-13T18:09:30.757Z","status":"PENDING"},{"time":"2025-02-13T18:09:30.769Z","status":"SEND"}],"time":"2025-02-13T18:09:30.849Z","status":"PENDING"},"agentId":"5616033475","creationTime":"2025-02-13T18:09:30.734Z","deviceId":"5616033475","id":"16031595","status":"PENDING","c8y_Command":{"text":"echo helloworld1"},"description":"echo helloworld","externalSource":{"externalId":"TST_draw_parallel_report","type":"c8y_Serial"}}
2025-02-13T18:09:30.913020Z c8y/s/ds 511,TST_draw_parallel_report,echo helloworld1
2025-02-13T18:09:30.971300Z c8y/s/us 504,16031595
2025-02-13T18:09:30.971371Z c8y/s/us 506,16031595,"helloworld1