Non-technical Description

The Problem

When syncing TIS data to TSS there are relationships between data that we have to be aware of, for example a Site or Post will have many Placements associated with it. Around 20,000 isn’t unusually for sites, and around 1000 for posts though there are some big outliers introduced for various workarounds, like a post with 64,000 placements.

Open

A TIS post “expanding” in to many related placement

When we receive updates to a site or post we need to update all related placements, but due to the large number of placements associated with some sites /posts it is challenging to process them all as part of the same update. Instead, we identify all placements that need to be updated and queue them to be processed one by one.

Open

Site-related placements queued to be processed by TSS

As shown, the related placements are identified by checking which placements we already have in the TSS database and this is where the problem potentially starts!

When a Placement is deleted, the associated Placement Specialty record is also deleted. To understand how the queuing becomes a problem lets focus on how that delete may look to TSS.

As we can see, something unexpected happens. The Placement Specialty deletion is received first and because we have no way of knowing the placement was already deleted, we grab the current data of the associated placement and re-queue it in order to trigger the trainee profile to be updated.

Next, we receive the placement deletion and we perform a few different actions

1. The placement is removed from the trainee profile

2. Any scheduled notifications associated with the placement are removed

3. Any required actions associated with the placement are removed

4. We remove the copy of placement from the TSS sync database

At this point, everything is as it should be. But, when the next message is received we treat it as an update to the placement, which triggers a few different actions

1. The placement is added to the trainee profile

2. Scheduled notifications associated with the placement are created

3. Required actions associated with the placement are created

4. We add a copy of the placement to the TSS sync database

We’ve just undone the deletion!
This same situation can also occur with update scenarios when multiple changes are made quickly, or related records are updated together. The original data, gets queued behind the updated data and we end up “reverting” the TIS update.

The Solution

The change required to fix this is a subtle but significant change to how we queue the original placement. We now queue a reference to the Placement (its ID) instead of using the original data.

When the reference is received we now get the latest version of the placement data.

In our delete scenario the placement is already gone, so after making one last request to TIS to send us any missing data we discard the request to re-process the placement. Leaving the deletion intact.

While there is no guarantee that this particular problem is the source of all data consistency problems, it does explain many of the synchronisation issues we’ve observed and had reported. Such as “orphaned” programme and placement data which requires manual intervention.

Trigger

Almost concurrent deletion events for placements and placement specialties are not always being handled in the correct sequence, resulting in the reinsertion of just-deleted placement records.

Detection

Issue reported by LOs 13 Nov 2024.

• Initial report: https://hee-nhs-tis.slack.com/archives/C03G3UK3U82/p1731513213318419

5 Whys (or other analysis of Root Cause)

• The example given is for placement 2568353 for trainee 319330. We sent a ‘zombie’ 12-week placement notification for this:
  2024-11-13T01:24:45.607Z INFO 1 --- [eduler_Worker-1] u.n.t.t.n.service.NotificationService : Sent DEFAULT.PLACEMENT_UPDATED_WEEK_12-2568353 notification for 2568353 (In Post, starting 2025-02-05) to mubarakdanyaro@gmail.com using template v1.0.0

• We still have that placement in our sync MongoDb, though it no longer exists in TIS.

• We received a delete instruction in tis-trainee-sync for the placement specialty and then the placement at roughly2024-10-25T09:31:11.3 . After the placement specialty delete, the service tried to resync the placement, apparently retrieving it at 2024-10-25T09:31:11.369Z before it was deleted from the db/cache, and then reinserting it.

  The key tis-trainee-sync log lines show this (full logs attached):

  2024-10-25T09:31:11.368Z DEBUG 1 --- [ontainer#2-1234] .t.t.s.e.PlacementSpecialtyEventListener : After placement specialty delete, search for placement 2568353 to re-sync. 2024-10-25T09:31:11.369Z DEBUG 1 --- [ontainer#2-1234] .t.t.s.e.PlacementSpecialtyEventListener : Placement Record(tisId=2568353, data={placementAddedDate=2024-05-24T08:50:40Z, lifecycleState=APPROVED, gradeId=306, siteCode=J81052, postId=233420, dateFrom=2025-02-05, placementWholeTimeEquivalent=1, traineeId=319330, placementType=In Post, dateTo=2025-08-05, siteId=16489, id=2568353}, metadata={}, type=null, operation=null, schema=tcs, table=Placement) found, queuing for re-sync.

  Code lines from: https://github.com/Health-Education-England/tis-trainee-sync/blob/958dd07fb543a2a9c304b4c93a039a399e582f4c/src/main/java/uk/nhs/hee/tis/trainee/sync/event/PlacementSpecialtyEventListener.java#L123

  Even though the subsequent request for the placement specialty from TIS will not succeed, this does not affect the ‘enrichment’ status of the re-inserted placement record, which will then be synced to the details service. We are unable to verify at this point that the request ended up in the corresponding DLQ (tis-trainee-sync-prod-request-interim-dlq.fifo) as the retention period is only 4 days.

   

• The deleted and resurrected placement seems to have been deleted and then reinserted into the trainee profile as expected. Logs as follows:

  2024-10-25T09:31:11.444Z INFO 1 --- [io-8203-exec-79] u.n.h.t.details.api.PlacementResource : Delete placement with TIS ID 2568353 of trainee with TIS ID 319330 2024-10-25T09:31:11.466Z INFO 1 --- [io-8203-exec-95] u.n.h.t.details.api.PlacementResource : Update placement of trainee with TIS ID 319330 with PlacementDto PlacementDto(tisId=2568353, startDate=2025-02-05, endDate=2025-08-05, site=SiteDto(name=LIFEBOAT QUAY MEDICAL CENTRE, knownAs=LIFEBOAT QUAY MEDICAL CENTRE (J81052), location=UNIT A, LIFEBOAT QUAY, POOLE ), otherSites=[], grade=ST1, specialty=null, subSpecialty=null, postAllowsSubspecialty=false, otherSpecialties=[], placementType=In Post, employingBody=University Hospitals Dorset NHS Foundation Trust, trainingBody=NHS DORSET ICB - 11J, wholeTimeEquivalent=1, status=null, signature=null)

   

• The first delete instruction was also actioned by the notification service:

  2024-10-25T09:31:11.529Z INFO 1 --- [ntContainer#6-6] u.n.t.t.n.event.PlacementListener : Handling placement delete event PlacementEvent[tisId=2568353, recrd=RecordDto(data={placementAddedDate=2024-05-24T08:50:40Z, lifecycleState=APPROVED, gradeId=306, siteCode=J81052, postId=233420, dateFrom=2025-02-05, placementWholeTimeEquivalent=1, traineeId=319330, placementType=In Post, dateTo=2025-08-05, siteId=16489, id=2568353}, metadata={})]. 2024-10-25T09:31:11.577Z INFO 1 --- [ntContainer#6-6] u.n.t.t.n.service.NotificationService : Removed any stale notification scheduled for PLACEMENT_UPDATED_WEEK_12-2568353 2024-10-25T09:31:11.586Z INFO 1 --- [ntContainer#6-6] u.n.t.t.n.service.NotificationService : Removed any stale notification scheduled for PLACEMENT_ROLLOUT_2024_CORRECTION-2568353

  and then the reinserted record was in turn rescheduled a minute later, leading to the incorrect notification mentioned above:

   

Resolution

• The sync service was modified to better ensure that old data can not make its way back in to the system.

• Queue timings were changed to try and eliminate race conditions that cause re-insertion of data if it is requested during deletion

• The process for identifying and deleting placements has been documented to assist with any future need to re-run the delete

Timeline

All times GMT unless otherwise indicated.

• Nov 13, 2024 15:05 Incorrect notifications reported by LOs. In addition, there has been a steady stream of requests for manual profile re-syncs which may well reflect these incorrect placements retained in TSS.

• Nov 13, 2024 15:53 Issue reported on trainee-team-general Slack channel.

• Nov 14, 2024 11:30 Initial investigation into specific example identifies potential issue.

• Nov 20, 202417:07 - First fix deployed to preprod for testing, further timing issues identified

• Nov 26, 202411:37 - Second fix applied to preprod to resolve timing issues, verification proved difficult due to extremely long delete times

• Dec 4, 202410:38 - Fix deployed to resolve the preprod environment issues impacting verification (and general use)

• Dec 9, 202414:15 - Fixes deployed to production

• Dec 19, 2024??:?? - First attempt to delete leftover placements. 13k identified, 1.2k did not successfully delete as they were partially processed previously

• Dec 19, 202416:27 - Fix deployed to allow deletion of remaining 1.2k placements

• Dec 23, 202415:06 - Matching fix applied for PMs, small number of PMs identified and deleted successfully
  
  

Action Items

See also:

Lessons Learned