Sync2 Issues On Openmrs 1.x

Tags: #<Tag:0x00007fddec07c610> #<Tag:0x00007fddec07c520>

Introduction

For the past few days I have been trying to understand how Sync2 really works. I can’t claim I fully understand it but I believe I understand the basic workflow which in a nutshell looks as follows.

  1. Atomfeed module records events by intercepting API calls based on the configuration provided in JSON format.
  2. Sync2 reads these events as atom feeds, then process/synchronize them one by one. It does this by utilizing either FHIR or REST webservices module.

Observations/Challenges/Discussion

1. Atomfeed events’ timestamps

I am not sure if this matters but I have observed that due to MySQL timestamp’s precision limitation (no longer an issue for 5.6+), for the events recorded close to each other, it is almost impossible to tell the order of events except when one looks at the ids; the order which may sometimes matter, for example, when an encounter has to exist before an obs that belongs to it. As a result one ends up having a list of events that looks like below (these are obs with their associated encounter and a visit). As it can be seen some obs appear to have been created earlier than the encounter, I cross-checked and verified that that is not what is happening (The associated events may not have been created in order but the database objects they refer to have).

mysql> select id,timestamp, date_created, substring(tags,1,30) from event_records order by timestamp desc, date_created desc, id limit 40;
+-----+---------------------+---------------------+--------------------------------+
| id  | timestamp           | date_created        | substring(tags,1,30)           |
+-----+---------------------+---------------------+--------------------------------+
| 357 | 2019-11-04 11:50:47 | 2019-11-04 11:50:47 | observation,UPDATED,<?xml vers |
| 358 | 2019-11-04 11:50:47 | 2019-11-04 11:50:47 | observation,UPDATED,<?xml vers |
| 359 | 2019-11-04 11:50:47 | 2019-11-04 11:50:47 | observation,UPDATED,<?xml vers |
| 336 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | encounter,CREATED,<?xml versio |
| 337 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 338 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 339 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 340 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 341 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 342 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 343 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 344 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 345 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 346 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 347 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 348 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 349 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 350 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 351 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 352 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 353 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 354 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 355 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,CREATED,<?xml vers |
| 356 | 2019-11-04 11:50:47 | 2019-11-04 11:50:46 | observation,UPDATED,<?xml vers |
| 321 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 322 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 323 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 324 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 325 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 326 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 327 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 328 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 329 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 330 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 331 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 332 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 333 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | visit,CREATED,<?xml version="1 |
| 334 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 335 | 2019-11-04 11:50:45 | 2019-11-04 11:50:45 | observation,CREATED,<?xml vers |
| 304 | 2019-11-04 11:50:45 | 2019-11-04 11:50:44 | observation,CREATED,<?xml vers |
+-----+---------------------+---------------------+--------------------------------+

2. Sync2 events processing

I have noticed that sometimes the sync2 audit log will show the events have failed to process but when I examine the database I realize the objects associated with those events are already there, making it seem like they are false alarms.

Now, let us consider an html form which creates an encounter with several obs. The atomfeed module will create an event for the encounter and for each of the obs. Also when using rest sync2 pulls the objects with v=full representation. I suspect the order of processing of the events does not necessary match the order in which the objects were created/updated in the parent system(maybe because of issue #1 above or something else). As a result if some obs are pulled before the parent encounter, they will fail since the encounter is not yet synchronized. Nevertheless, when the encounter is finally pulled (with full representation all obs will be included as well), those obs will be successfully processed creating the aforementioned situation.

Therefore, based on the above there are two issues, at least when using rest, which are:-

  1. For an encounter with obs there is double processing (this is regardless of whether the order will be maintained or not)
  2. If the order is not maintained the some events fail while they would not if the order was maintained.

Way forward: I can’t think of a way to eliminate the double processing without major changes to either sync2, atomfeed or both. Fortunately I think we can eliminate the unnecessary failures by adding a check during processing that will ensure the parent objects have already been synchronized before synchronizing the children for the CREATE events.

I am sure there are plenty of issues to be addressed. Please take this as an attempt to garner support and interest in the community.

If you are using or plan to use Sync2 in OpenMRS 1.x please reach out.

2 Likes

@willa i like the detailed analysis and your taking precious time to share your findings with the community. Please keep this up! :slight_smile:

Do you plan to invest some time in addressing any of the above?

Yes we are investing time in this. Hopefully some other community members will join the efforts.

1 Like

That is awesome!!! Please keep us updated. We would also love to invest some time together with your team. :slight_smile:

1 Like