1.7 5708 Very poor performance of history:medication on some patients

The history:medication() function performs very poorly on some patients. As can be seen below the one use of this function (in generating a vaccination certificate) results in two  MySQL queries (one for limit 25 and the second for limit 25,25) that result in a serial scan of the acts table - and as you can see this contains nearly 680,000 records - and this takes 54 seconds for each scan. 

 # Time: 140109 16:43:48
# User@Host: openvpms[openvpms] @  [127.0.0.1]
# Query_time: 54.062500  Lock_time: 0.000000 Rows_sent: 12  Rows_examined: 679541
SET timestamp=1389257028;
select actdoimpl0_.act_id as act1_0_, actdoimpl0_.version as version0_, actdoimpl0_.arch_short_name as arch3_0_, actdoimpl0_.arch_version as arch4_0_, actdoimpl0_.linkId as linkId0_, actdoimpl0_.name as name0_, actdoimpl0_.description as descript7_0_, actdoimpl0_.active as active0_, actdoimpl0_.title as title0_, actdoimpl0_.activity_start_time as activity10_0_, actdoimpl0_.activity_end_time as activity11_0_, actdoimpl0_.reason as reason0_, actdoimpl0_.status as status0_, actdoimpl0_1_.quantity as quantity2_, actdoimpl0_1_.fixed_amount as fixed3_2_, actdoimpl0_1_.unit_amount as unit4_2_, actdoimpl0_1_.fixed_cost as fixed5_2_, actdoimpl0_1_.unit_cost as unit6_2_, actdoimpl0_1_.tax_amount as tax7_2_, actdoimpl0_1_.total as total2_, actdoimpl0_1_.allocated_amount as allocated9_2_, actdoimpl0_1_.credit as credit2_, actdoimpl0_1_.printed as printed2_, actdoimpl0_2_.doc_version as doc2_3_, actdoimpl0_2_.file_name as file3_3_, actdoimpl0_2_.mime_type as mime4_3_, actdoimpl0_2_.printed as printed3_, actdoimpl0_2_.document_id as document6_3_, case when actdoimpl0_1_.financial_act_id is not null then 1 when actdoimpl0_2_.document_act_id is not null then 2 when actdoimpl0_.act_id is not null then 0 end as clazz_ from acts actdoimpl0_ left outer join financial_acts actdoimpl0_1_ on actdoimpl0_.act_id=actdoimpl0_1_.financial_act_id left outer join document_acts actdoimpl0_2_ on actdoimpl0_.act_id=actdoimpl0_2_.document_act_id inner join participations participat1_ on actdoimpl0_.act_id=participat1_.act_id inner join participations participat2_ on actdoimpl0_.act_id=participat2_.act_id inner join entities entitydoim3_ on participat2_.entity_id=entitydoim3_.entity_id inner join entity_relationships targetenti4_ on entitydoim3_.entity_id=targetenti4_.target_id inner join entities entitydoim5_ on targetenti4_.source_id=entitydoim5_.entity_id where actdoimpl0_.arch_short_name='act.patientMedication' and participat1_.arch_short_name='participation.patient' and participat1_.entity_id=19914 and participat1_.act_arch_short_name='act.patientMedication' and participat2_.arch_short_name='participation.product' and (entitydoim3_.arch_short_name='product.service' or entitydoim3_.arch_short_name='product.medication' or entitydoim3_.arch_short_name='product.merchandise' or entitydoim3_.arch_short_name='product.template') and targetenti4_.arch_short_name='entityRelationship.productTypeProduct' and entitydoim5_.arch_short_name='entity.productType' and entitydoim5_.name='Vaccination' order by actdoimpl0_.activity_start_time desc, actdoimpl0_.act_id desc limit 25;
# Time: 140109 16:44:45
# User@Host: openvpms[openvpms] @  [127.0.0.1]
# Query_time: 54.062500  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 679541
SET timestamp=1389257085;
select actdoimpl0_.act_id as act1_0_, actdoimpl0_.version as version0_, actdoimpl0_.arch_short_name as arch3_0_, actdoimpl0_.arch_version as arch4_0_, actdoimpl0_.linkId as linkId0_, actdoimpl0_.name as name0_, actdoimpl0_.description as descript7_0_, actdoimpl0_.active as active0_, actdoimpl0_.title as title0_, actdoimpl0_.activity_start_time as activity10_0_, actdoimpl0_.activity_end_time as activity11_0_, actdoimpl0_.reason as reason0_, actdoimpl0_.status as status0_, actdoimpl0_1_.quantity as quantity2_, actdoimpl0_1_.fixed_amount as fixed3_2_, actdoimpl0_1_.unit_amount as unit4_2_, actdoimpl0_1_.fixed_cost as fixed5_2_, actdoimpl0_1_.unit_cost as unit6_2_, actdoimpl0_1_.tax_amount as tax7_2_, actdoimpl0_1_.total as total2_, actdoimpl0_1_.allocated_amount as allocated9_2_, actdoimpl0_1_.credit as credit2_, actdoimpl0_1_.printed as printed2_, actdoimpl0_2_.doc_version as doc2_3_, actdoimpl0_2_.file_name as file3_3_, actdoimpl0_2_.mime_type as mime4_3_, actdoimpl0_2_.printed as printed3_, actdoimpl0_2_.document_id as document6_3_, case when actdoimpl0_1_.financial_act_id is not null then 1 when actdoimpl0_2_.document_act_id is not null then 2 when actdoimpl0_.act_id is not null then 0 end as clazz_ from acts actdoimpl0_ left outer join financial_acts actdoimpl0_1_ on actdoimpl0_.act_id=actdoimpl0_1_.financial_act_id left outer join document_acts actdoimpl0_2_ on actdoimpl0_.act_id=actdoimpl0_2_.document_act_id inner join participations participat1_ on actdoimpl0_.act_id=participat1_.act_id inner join participations participat2_ on actdoimpl0_.act_id=participat2_.act_id inner join entities entitydoim3_ on participat2_.entity_id=entitydoim3_.entity_id inner join entity_relationships targetenti4_ on entitydoim3_.entity_id=targetenti4_.target_id inner join entities entitydoim5_ on targetenti4_.source_id=entitydoim5_.entity_id where actdoimpl0_.arch_short_name='act.patientMedication' and participat1_.arch_short_name='participation.patient' and participat1_.entity_id=19914 and participat1_.act_arch_short_name='act.patientMedication' and participat2_.arch_short_name='participation.product' and (entitydoim3_.arch_short_name='product.service' or entitydoim3_.arch_short_name='product.medication' or entitydoim3_.arch_short_name='product.merchandise' or entitydoim3_.arch_short_name='product.template') and targetenti4_.arch_short_name='entityRelationship.productTypeProduct' and entitydoim5_.arch_short_name='entity.productType' and entitydoim5_.name='Vaccination' order by actdoimpl0_.activity_start_time desc, actdoimpl0_.act_id desc limit 25, 25;
 

Investigation shows that there are two problems:
1) the OPV code, on receiving 12 records from its limit 25 request, the requests limit 25,25. It should only make the second request if 25 records were returned to the first limit 25 call.

2) MySQL's query optimiser is getting confused and ends up doing a serial scan.  Testing shows that it the query is reformulated into one that uses a subquery to retrieve all medication acts for the patient in the specified period, and then asks for those that match the requested product type, then MySQL does not get confused.

We are fairly certain that the problem only occurs with animals with a long medical history, ie for those with a short history, the MySQL query optimiser gets things right and query runs fast. [I suspect the OPV code is still making an second unnecessary limit 25,25 call but seeing the query runs fact this is not significant.]

As a result of this problem we are using the work-around that for long-history animals we are going back to RxWorks to generate the vaccination certificate and manually adding the post OpenVPMS cutover ones. This work-around is not going to be viable for much longer, and hence we would appreciate a fix.

Note that there has been significant off-forum discussion with Tim G about this problem, and as a help to him doing testing with large databases, we will be providing an obfuscated version of ours.

Regards, Tim G

Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.

Re: 1.7 5708 Very poor performance of history:medication on ...

I'll look at this next week.

Regards,

-Tim A

Re: 1.7 5708 Very poor performance of history:medication on ...

I've restructured the query to filter on product type using a correlated subquery.

Change applied in revision 5712.

-Tim A

Syndicate content