Hello,
I am developing a service that works on documents that holds a “todo” field containing a pending set of operations that are updated by multiple service instances.
Consider the case when I am running two instance of my service, Consumer 1 and Consumer 2.
Consumer 1 receive a message from a queue and starts working on a claim meanwhile Consumer 2 receives messages for the same claim but it cannot work on the same claim because it is from Consumer 1 so it sets the “todo” field with the pending operations.
The following are the logs from the two Consumer.
Consumer 1:
2024-05-21 10:38:14,802 | INFO | consumer:168 | Received message # 1: {"event":"UPDATE","update_types":["TRIPS"],"claim_number":"1-8101-2023-xxxx","data_apertura":"2023-06-08T00:00:00Z","data_accadimento":"2023-04-09T00:00:00Z","data_ora_accadimento":"2023-04-09T00:00:00Z","longitudine_accadimento":7.67994,"latitudine_accadimento":45.06236,"livello_geocodifica":"Livello geocodifica test","citta_accadimento":"xxxx","provincia_accadimento":"xx","indirizzo_accadimento":null,"numero_civico_accadimento":null,"cap_accadimento":"10100","lob":"01LOBAUTO","vda":[{"ramo_sx":39,"tipo_sx":22}],"targa":"xxxx","box":"N","descrizione_evento":"Descrizione evento test","document_id":null}
...
2024-05-21 10:39:34,130 | DEBUG | dispatcher_service:369 | Current pending todo set: {LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.SCORE: 'SCORE'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.TRIPS: 'TRIPS'>, date=datetime.datetime(2024, 5, 28, 10, 38, 14, 803000))}
2024-05-21 10:39:34,314 | INFO | dispatcher_service:384 | Claim 1-8101-2023-xxxx status set to DONE
2024-05-21 10:39:34,400 | INFO | publisher:186 | Published message {"claim_number":"1-8101-2023-xxxx","score":[{"score_level":-1,"score_text":"","ramo_sx":39,"tipo_sx":22}],"score_status":"Complete"}
Consumer 2:
2024-05-21 10:38:15,823 | INFO | consumer:168 | Received message # 1: {"event":"NEW","update_types":null,"claim_number":"1-8101-2023-xxxx","data_apertura":"2023-06-08T00:00:00Z","data_accadimento":"2023-04-09T00:00:00Z","data_ora_accadimento":"2023-04-09T00:00:00Z","longitudine_accadimento":7.67994,"latitudine_accadimento":45.06236,"livello_geocodifica":"Livello geocodifica test","citta_accadimento":"TORINO","provincia_accadimento":"TO","indirizzo_accadimento":null,"numero_civico_accadimento":null,"cap_accadimento":"10100","lob":"01LOBAUTO","vda":[{"ramo_sx":39,"tipo_sx":22}],"targa":"xxxx","box":"N","descrizione_evento":"Descrizione evento test","document_id":null}
2024-05-21 10:38:16,221 | INFO | dispatcher_service:135 | Claim 1-8101-2023-xxxx is being worked by another consumer
2024-05-21 10:38:16,221 | DEBUG | dispatcher_service:139 | Updated claim todo set {LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.FORWARD: 'FORWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.SCORE: 'SCORE'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.BACKWARD: 'BACKWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.TRIPS: 'TRIPS'>, date=datetime.datetime(2024, 5, 28, 10, 38, 14, 803000))}
2024-05-21 10:38:16,701 | INFO | dispatcher_service:635 | Saved Bretella message 664c7998a19eaad7a0e08e4f
2024-05-21 10:38:16,741 | INFO | consumer:192 | Acknowledging message # 1
2024-05-21 10:38:16,782 | INFO | consumer:168 | Received message # 2: {"event":"UPDATE","update_types":["SCORE"],"claim_number":"1-8101-2023-xxxx","data_apertura":"2023-06-08T00:00:00Z","data_accadimento":"2023-04-09T00:00:00Z","data_ora_accadimento":"2023-04-09T00:00:00Z","longitudine_accadimento":7.67994,"latitudine_accadimento":45.06236,"livello_geocodifica":"Livello geocodifica test","citta_accadimento":"TORINO","provincia_accadimento":"TO","indirizzo_accadimento":null,"numero_civico_accadimento":null,"cap_accadimento":"10100","lob":"01LOBAUTO","vda":[{"ramo_sx":39,"tipo_sx":22}],"targa":"xxxx","box":"N","descrizione_evento":"Descrizione evento test","document_id":null}
2024-05-21 10:38:17,161 | INFO | dispatcher_service:209 | Claim 1-8101-2023-xxxx is being worked by another consumer
2024-05-21 10:38:17,162 | DEBUG | dispatcher_service:213 | Updated claim todo set {LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.FORWARD: 'FORWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.SCORE: 'SCORE'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.BACKWARD: 'BACKWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.TRIPS: 'TRIPS'>, date=datetime.datetime(2024, 5, 28, 10, 38, 14, 803000))}
2024-05-21 10:38:17,670 | INFO | dispatcher_service:635 | Saved Bretella message 664c7999a19eaad7a0e08e52
2024-05-21 10:38:17,670 | INFO | consumer:192 | Acknowledging message # 2
2024-05-21 10:38:17,711 | INFO | consumer:168 | Received message # 3: {"event":"UPDATE","update_types":["TRIPS"],"claim_number":"1-8101-2023-xxxx","data_apertura":"2023-06-08T00:00:00Z","data_accadimento":"2023-04-09T00:00:00Z","data_ora_accadimento":"2023-04-09T00:00:00Z","longitudine_accadimento":7.67994,"latitudine_accadimento":45.06236,"livello_geocodifica":"Livello geocodifica test","citta_accadimento":"TORINO","provincia_accadimento":"TO","indirizzo_accadimento":null,"numero_civico_accadimento":null,"cap_accadimento":"10100","lob":"01LOBAUTO","vda":[{"ramo_sx":39,"tipo_sx":22}],"targa":"xxxx","box":"N","descrizione_evento":"Descrizione evento test","document_id":null}
2024-05-21 10:38:18,051 | INFO | dispatcher_service:209 | Claim 1-8101-2023-xxxx is being worked by another consumer
2024-05-21 10:38:18,051 | DEBUG | dispatcher_service:213 | Updated claim todo set {LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.FORWARD: 'FORWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.SCORE: 'SCORE'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.BACKWARD: 'BACKWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.TRIPS: 'TRIPS'>, date=datetime.datetime(2024, 5, 28, 10, 38, 14, 803000))}
2024-05-21 10:38:18,580 | INFO | dispatcher_service:635 | Saved Bretella message 664c799aa19eaad7a0e08e55
2024-05-21 10:38:18,580 | INFO | consumer:192 | Acknowledging message # 3
2024-05-21 10:38:18,620 | INFO | consumer:168 | Received message # 4: {"event":"UPDATE","update_types":["DOCUMENT"],"claim_number":"1-8101-2023-xxxx","data_apertura":"2023-06-08T00:00:00Z","data_accadimento":"2023-04-09T00:00:00Z","data_ora_accadimento":"2023-04-09T00:00:00Z","longitudine_accadimento":7.67994,"latitudine_accadimento":45.06236,"livello_geocodifica":"Livello geocodifica test","citta_accadimento":"TORINO","provincia_accadimento":"TO","indirizzo_accadimento":null,"numero_civico_accadimento":null,"cap_accadimento":"10100","lob":"01LOBAUTO","vda":[{"ramo_sx":39,"tipo_sx":22}],"targa":"xxxx","box":"N","descrizione_evento":"Descrizione evento test","document_id":null}
2024-05-21 10:38:18,954 | INFO | dispatcher_service:209 | Claim 1-8101-2023-xxxx is being worked by another consumer
2024-05-21 10:38:18,954 | DEBUG | dispatcher_service:213 | Updated claim todo set {LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.FORWARD: 'FORWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.BACKWARD: 'BACKWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.TRIPS: 'TRIPS'>, date=datetime.datetime(2024, 5, 28, 10, 38, 14, 803000)), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.SCORE: 'SCORE'>, date=None)}
2024-05-21 10:38:19,443 | INFO | dispatcher_service:635 | Saved Bretella message 664c799ba19eaad7a0e08e58
2024-05-21 10:38:19,444 | INFO | consumer:192 | Acknowledging message # 4
2024-05-21 10:38:19,484 | INFO | consumer:168 | Received message # 5: {"event":"UPDATE","update_types":["SCORE"],"claim_number":"1-8101-2023-xxxx","data_apertura":"2023-06-08T00:00:00Z","data_accadimento":"2023-04-09T00:00:00Z","data_ora_accadimento":"2023-04-09T00:00:00Z","longitudine_accadimento":7.67994,"latitudine_accadimento":45.06236,"livello_geocodifica":"Livello geocodifica test","citta_accadimento":"TORINO","provincia_accadimento":"TO","indirizzo_accadimento":null,"numero_civico_accadimento":null,"cap_accadimento":"10100","lob":"01LOBAUTO","vda":[{"ramo_sx":39,"tipo_sx":22}],"targa":"xxxx","box":"N","descrizione_evento":"Descrizione evento test","document_id":null}
2024-05-21 10:38:19,836 | INFO | dispatcher_service:209 | Claim 1-8101-2023-xxxx is being worked by another consumer
2024-05-21 10:38:19,837 | DEBUG | dispatcher_service:213 | Updated claim todo set {LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.FORWARD: 'FORWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.SCORE: 'SCORE'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.BACKWARD: 'BACKWARD'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.TRIPS: 'TRIPS'>, date=datetime.datetime(2024, 5, 28, 10, 38, 14, 803000))}
2024-05-21 10:38:20,391 | INFO | dispatcher_service:635 | Saved Bretella message 664c799ca19eaad7a0e08e5b
2024-05-21 10:38:20,392 | INFO | consumer:192 | Acknowledging message # 5
As you can see, the first message is received by Consumer 1 that updates the todo set at 2024-05-21 10:38:14,802 and then starts working on the claim. Meanwhile Consumer 2 receives more messages and it updates the todo set as well, with the final update occurring at 2024-05-21 10:38:19,837. After that, Consumer 1 finishes working on the claim and it reads the todo set at 2024-05-21 10:39:34,400, one second after the final update by Consumer 2. However it reads:
{LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.SCORE: 'SCORE'>, date=None), LorentzClaimTodoOperation(operation=<LorentzClaimOperationType.TRIPS: 'TRIPS'>, date=datetime.datetime(2024, 5, 28, 10, 38, 14, 803000))}
that is not the updated value by the Consumer 2!
Do you have an explanation on why this is happening?