Error: Cursor fails to make progress
# support
j
Getting an OperationOutcome on a Bulk export where it fails with a diagnostic message like this: "Error: Cursor fails to make progress" This comes from the Search implementation here: https://github.com/medplum/medplum/blob/e64d633bb58dade947fa3715ce6dd83748bf375d/packages/server/src/fhir/search.ts#L600-L604 Conceptually, this makes sense:
Copy code
// In order to make progress, the lastUpdated timestamp must change from the first entry of the current page
      // to the first entry of the next page; otherwise we'd make the exact same request in a loop
But the issue here is that if a large number of resources are inserted quickly, and they have the same lastUpdated timestamp - and that their number exceeds the page size, well, we're kind of SOL on an export no?
c
Hey @joshua_kelly , good question and correct diagnosis The bulk export pagination logic relies on the _lastUpdated timestamp changing between pages to make progress. When a batch of resources larger than the page size (bulk data export uses 1000) shares the exact same _lastUpdated value, the cursor gets stuck. This situation is quite rare under normal operation, as system-generated timestamps have millisecond precision. It usually points to a scenario where the _lastUpdated field was manually set during a large data import. Our general guidance is to avoid manually setting that field, as it can lead to this exact pagination problem. You might be thinking, "Why not just add _id as a secondary sort key?" We actually explored that path before, but sorting by _id across the entire dataset for these paginated queries introduced significant performance degradation. To keep searches fast and efficient for everyone, we've intentionally optimized for the standard use case where timestamps are unique. Since modifying the core server logic isn't practical, the one approach is to address the data itself. We can help you with a script that would: Find all the resources sharing the problematic _lastUpdated timestamp. Apply a small "jitter" to each timestamp (e.g., adding a few milliseconds sequentially) to make them unique. This would break the logjam and allow the bulk export cursor to proceed as designed. It's a one-time data cleanup operation that resolves the root cause. Let us know if you'd like to explore that
j
Yeah hm, that's really pragmatic - we'll have to try that to start In particular just finding the problematic resources Because I am not 100% sure what the source of the lastUpdated issue is - I am relatively certain it's not a value we deliberately set in a large data import - but it's possible
@cody yeah - turns out, definitely need a jitter solution here, thanks to the nice new Super AsyncJob dashboard, realized that v3 data migration has been failing for similar reasons Do you have a ready example? I'll post one if no
Working on this now, will post the code for others
Something like this seems efficient Basically, hash the UUID to produce a jitter value in ms - A cluster of 100 identical timestamps is thrown into 2 048 microsecond-wide “buckets.” - Because the offset is a deterministic function of id, you can re-run the command without ever moving a row twice. --- -- Count total rows in clusters with more than 99 duplicates SELECT COUNT(*) AS num_rows_in_large_clusters FROM "Encounter" WHERE "lastUpdated" IN ( SELECT "lastUpdated" FROM "Encounter" GROUP BY "lastUpdated" HAVING COUNT(*) > 99 ); -- For each cluster with more than 99 duplicate stamps, add a jitter to the lastUpdated timestamp WITH cluster_gt_99 AS ( SELECT "lastUpdated" FROM "Encounter" GROUP BY "lastUpdated" HAVING COUNT(*) > 99 ) UPDATE "Encounter" r SET "lastUpdated" = r."lastUpdated" + ( (('x'||substr(md5(r.id::text),1,6))::bit(24)::int & 2047)::text || ' microseconds')::interval WHERE r."lastUpdated" IN (SELECT "lastUpdated" FROM cluster_gt_99); -- Count total rows in clusters with more than 99 duplicates after jittering SELECT COUNT(*) AS num_rows_in_large_clusters FROM "Encounter" WHERE "lastUpdated" IN ( SELECT "lastUpdated" FROM "Encounter" GROUP BY "lastUpdated" HAVING COUNT(*) > 99 );
To add a bit more color to the issue, and the root cause, this wasn't actually us inserting the same value intentionally from some process that was creating the timestamp. Rather, this is the result of us trying to respect the original lastUpdated value as retrieved from another FHIR server, and then storing it
Hm, this turned out much trickier - since the denormalized lastUpdate column isn't actually used here (d'oh!)
Then I tried the approach of using acutal FHIR update operation - but lastUpdated is special, and is automatically set
r
@joshua_kelly thanks so much for sharing your solution with us. Please keep us informed of your progress > Rather, this is the result of us trying to respect the original lastUpdated value as retrieved from another FHIR server, and then storing it Does that mean you were writing directly to the DB in these cases?
j
No, we'd (as a general rule) would never do that for a normal operation - for all of the obvious reasons Medplum's createOrUpdate behavior for the SuperAdmin user allows you to set the lastUpdated - but only on initial create - we take advantage of that feature @rahul1
In the case of resolving this, we've had to use db writes due to the fact that lastUpdated cannot be set by the API / repository level changes (unless you also mutate the resource itself)
What we've settled into is something like this:
Copy code
-- Count how many records would be affected
SELECT 
    COUNT(*) as total_records_to_jitter,
    COUNT(DISTINCT date_trunc('milliseconds', "lastUpdated")) as unique_timestamp_groups
FROM "Observation" 
WHERE date_trunc('milliseconds', "lastUpdated") IN (
    SELECT date_trunc('milliseconds', "lastUpdated")
    FROM "Observation"
    GROUP BY date_trunc('milliseconds', "lastUpdated")
    HAVING COUNT(*) > 250
);
That's used to identify the records
Then this monster is the jitter itself
Copy code
WITH jittered_updates AS (
    SELECT 
        pr.id,
        pr."lastUpdated" as original_timestamp,
        -- Generate MD5 hash from ID and timestamp, then convert to numeric offset
        -- Use the first 8 characters of MD5 hash as hex, convert to decimal
        -- Then modulo by 1000 to get milliseconds offset (0-999ms)
        (('x' || substr(md5(pr.id || pr."lastUpdated"::text), 1, 8))::bit(32)::int % 1000) as jitter_ms,
        -- Calculate the new jittered timestamp
        pr."lastUpdated" + INTERVAL '1 millisecond' * (('x' || substr(md5(pr.id || pr."lastUpdated"::text), 1, 8))::bit(32)::int % 1000) as jittered_timestamp
    FROM "Observation" pr
    WHERE date_trunc('milliseconds', pr."lastUpdated") IN (
        SELECT date_trunc('milliseconds', "lastUpdated")
        FROM "Observation"
        GROUP BY date_trunc('milliseconds', "lastUpdated")
        HAVING COUNT(*) > 250
    )
    ORDER BY pr.id  -- Consistent ordering for chunking
    LIMIT 5000  -- Process first 5000 records
),
Copy code
-- Update both the lastUpdated column and the JSON content
updated_records AS (
    UPDATE "Observation" 
    SET 
        "lastUpdated" = ju.jittered_timestamp,
        "content" = CASE 
            WHEN ("content"::json -> 'meta' ->> 'lastUpdated') IS NOT NULL THEN
                -- Replace the existing lastUpdated value in JSON with the jittered timestamp
                replace(
                    "content",
                    '"lastUpdated":"' || ("content"::json -> 'meta' ->> 'lastUpdated') || '"',
                    '"lastUpdated":"' || to_char(ju.jittered_timestamp AT TIME ZONE 'UTC', 'YYYY-MM-DD"T"HH24:MI:SS.MS"Z"') || '"'
                )
            ELSE
                "content"
            END
    FROM jittered_updates ju
    WHERE "Observation".id = ju.id
    RETURNING "Observation".id, ju.original_timestamp, ju.jitter_ms, "Observation"."lastUpdated" as new_timestamp
)
SELECT 
    COUNT(*) as records_updated_chunk_1,
    MIN(jitter_ms) as min_jitter_ms,
    MAX(jitter_ms) as max_jitter_ms,
    AVG(jitter_ms) as avg_jitter_ms
FROM updated_records;
It writes both the column and the resource itself - which is necessary here
It would probably be better to have a data migration
I've managed to advance to data migration v8 now, and am expecting to be up to v12 soon
We're live on 4.2.6 now and all data migrations were successful
154 Views