Duplicate Cumulocity devicecontrol messages aren't being ignored #3721
Description
Describe the bug
#3454 was created to de-duplicate any incoming operations coming from Cumulocity, to avoid executing the operation twice.
However, this test run shows that the operation handler is triggered twice (about 40 milliseconds later)
Below shows the mqtt log showing that the c8y_Command operation (id: 19830895) is received twice AND processed twice (by noting the 506,19830895 messages which have different contents).
---- mqtt messages ----
2025-07-03T06:59:26.418551Z c8y/s/us 114,c8y_Command,c8y_DeviceProfile,c8y_DownloadConfigFile,c8y_LogfileRequest,c8y_RemoteAccessConnect,c8y_Restart,c8y_SoftwareUpdate,c8y_UploadConfigFile
2025-07-03T06:59:26.542605Z c8y/s/dat 71,<redacted>
2025-07-03T06:59:26.553273Z c8y/devicecontrol/notifications {"delivery":{"log":[],"time":"2025-07-03T06:59:26.457Z","status":"PENDING"},"agentId":"7019830853","creationTime":"2025-07-03T06:59:26.415Z","deviceId":"7019830853","id":"19830895","status":"PENDING","c8y_Command":{"text":"echo helloworld1"},"description":"echo helloworld","externalSource":{"externalId":"TST_hurtle_rectilinear_heater","type":"c8y_Serial"}}
2025-07-03T06:59:26.553402Z c8y/s/ds 511,TST_hurtle_rectilinear_heater,echo helloworld1
2025-07-03T06:59:26.594604Z c8y/s/us 504,19830895
2025-07-03T06:59:26.594820Z c8y/s/us 506,19830895,"helloworld1
"
2025-07-03T06:59:26.631124Z c8y/devicecontrol/notifications {"delivery":{"log":[],"time":"2025-07-03T06:59:26.476Z","status":"PENDING"},"agentId":"7019830853","creationTime":"2025-07-03T06:59:26.415Z","deviceId":"7019830853","id":"19830895","status":"PENDING","c8y_Command":{"text":"echo helloworld1"},"description":"echo helloworld","externalSource":{"externalId":"TST_hurtle_rectilinear_heater","type":"c8y_Serial"}}
2025-07-03T06:59:26.631268Z c8y/s/ds 511,TST_hurtle_rectilinear_heater,echo helloworld1
2025-07-03T06:59:26.676548Z c8y/s/us 504,19830895
2025-07-03T06:59:26.676617Z c8y/s/us 506,19830895,"helloworld1
"
2025-07-03T06:59:26.985366Z te/device/main///cmd/software_list/c8y-mapper-2025-07-03T06:59:25.75398553Z
2025-07-03T06:59:27.009475Z te/device/main/service/c8y-firmware-plugin {"@parent":"device/main//","@type":"service","name":"c8y-firmware-plugin","type":"service"}
2025-07-03T06:59:27.009609Z te/device/main/service/c8y-firmware-plugin/status/health {"pid":847,"status":"up","time":1751525966.957641}
2025-07-03T06:59:27.009758Z c8y/s/us 500
2025-07-03T06:59:27.050521Z te/device/main/service/c8y-firmware-plugin/twin/name "c8y-firmware-plugin"
2025-07-03T06:59:27.050637Z te/device/main/service/c8y-firmware-plugin/twin/type "service"
2025-07-03T06:59:27.050799Z c8y/s/us 102,TST_hurtle_rectilinear_heater:device:main:service:c8y-firmware-plugin,service,c8y-firmware-plugin,up
2025-07-03T06:59:27.050923Z c8y/s/us 102,TST_hurtle_rectilinear_heater:device:main:service:c8y-firmware-plugin,service,c8y-firmware-plugin,up
Test Case
The logs were taken from the following system test case.
Run shell custom operation for main device and publish the status
To Reproduce
The test currently sporadically fails on the Cloud CI server, where the original flaky test ticket is still open:
Expected behavior
Screenshots
Environment (please complete the following information):
- OS [incl. version]:
Debian - Hardware [incl. revision]:
Github Runner - System-Architecture [e.g. result of "uname -a"]:
amd64 / x86_64 - thin-edge.io version [e.g. 0.1.0]:
1.5.2~204+ge4688a7
Additional context