Project

Profile

Help

Bug #2145

closed

Match pattern not being optimized

Added by Milos Koscica over 9 years ago. Updated over 8 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Performance
Sprint/Milestone:
-
Start date:
2014-09-11
Due date:
% Done:

0%

Estimated time:
Legacy ID:
Applies to branch:
9.5, 9.6
Fix Committed on Branch:
9.6
Fixed in Maintenance Release:
Platforms:

Description

We have ran into an issue running the latest 9.5 version of Saxon in our production environment. We recently upgrade to he latest version in order to have the benefit of the latest upgrades/support but are currently having an issue where we are unable to complete a transformation using the saxon 9.5 version, which is taking hours and hours to run, while the same transformation with the same data runs in 6 seconds in the 9.4 version.

All of these are EE versions.

The test data I will provide was all run on a local desktop machine with Saxon 9.4 and Saxon 9.5 installed on windows. As well as the Saxon 9.4 and Saxon 9.5 java command line implementations.

The transformation provided along with the 1000 record input file provided runs in about 6 second in the Saxon 9.4 java version and about 15 seconds in the Transform.exe windows version.

The 9.5 version starts and as per the log, shows that it is making progress, but takes a long time to complete, as of yet we have not ye run a 9.5 to completion.


Files

IntermediateAssetFile_medline14n0017_12.xml (7.98 MB) IntermediateAssetFile_medline14n0017_12.xml this is the input file Milos Koscica, 2014-09-11 18:07
branch_i2a.zip (50.4 KB) branch_i2a.zip this is the xsl (run i2a.xsl) Milos Koscica, 2014-09-11 18:07
execute.bat (1.59 KB) execute.bat bat file used to execute the tests Milos Koscica, 2014-09-11 18:08
Results.xlsx (12.2 KB) Results.xlsx test data using different sizes of the same input file Milos Koscica, 2014-09-11 18:08
i2a_trunk_perffix.zip (51 KB) i2a_trunk_perffix.zip XSL Milos Koscica, 2014-09-15 21:24
Results.xlsx (16.6 KB) Results.xlsx Test Results Milos Koscica, 2014-09-15 21:24
IntermediateAssetFile_medline14n0017_12.zip (282 KB) IntermediateAssetFile_medline14n0017_12.zip input Milos Koscica, 2014-09-15 21:25
Actions #1

Updated by Michael Kay over 9 years ago

Many thanks for letting us know. We'll certainly look into it. It's probably some regression in optimizer behaviour. This doesn't happen very often but it's very hard to prevent - sometimes it's caused by adding an optimization, which gets in the way of another more powerful optimization.

Actions #2

Updated by Michael Kay over 9 years ago

  • Category set to Performance
  • Assignee set to Michael Kay
  • Priority changed from High to Normal

I'll be capturing my observations here as a sort of personal notebook, but sharing it just so you can see how I'm getting on.

Tried it on the development 9.6 branch and it crashed, so I'll put that on one side to be investigated later.

On 9.5, I changed the stylesheet so it only processes the first 5 records. Ran this with -TP output; the dominant cost is function i2a:process on line 149.

Ran with Java profiling, all the cost is going into tree.tidy.SiblingEnumeration, mostly called from UnionEnumeration, but IntersectEnumeration also features. There's no obvious use of union or intersect operations in i2a:process.

By breakpointing UniionEnumeration in the debugger, I see that it's the match pattern on line 16 of semanticMetadata.xsl that's causing the trouble: the pattern is

<xsl:template match="metadata/*[. intersect ../(&SEMANTIC_METADATA;)][1]" priority="1">

where the entity is defined as

funding | event | product | patent

                      | contract | grant | individual | databank

                      | chemical | geneSymbol | spaceFlightMission

A union expression of the form child::A | child::B | child::c ought to be optimized as child::*[self::A or self::B or self::C], but it doesn't look as if this optimization has happened.

Actions #3

Updated by Michael Kay over 9 years ago

Hand-optimized the relevant two template rules to what I think is the equivalent

<xsl:template match="metadata/*[self::funding | self::event | self::product | self::patent

| self::contract | self::grant | self::individual | self::databank

| self::chemical | self::geneSymbol | self::spaceFlightMission]"/>

<xsl:template match="metadata/*[self::funding | self::event | self::product | self::patent

| self::contract | self::grant | self::individual | self::databank

| self::chemical | self::geneSymbol | self::spaceFlightMission][1]" priority="1">

and we see a dramatic speed-up. So I think (a) this confirms that this is the problem area, and (b) you have a workaround. I now have to work out why Saxon 9.4 was optimizing this and 9.5 isn't.

Actions #4

Updated by Michael Kay over 9 years ago

  • Subject changed from Saxon 9.4 N EE performs better than Saxon 9.5N EE by a huge margin to Match pattern not being optimized
  • Status changed from New to Resolved

It turns out that in 9.5, the expressions used within a predicate in a match pattern are not put through the optimizer. In this particular case the effect of optimization is dramatic.

A patch is being developed. First attempt at a patch solves this performance problem, but causes regression for patterns that use local variables.

Actions #5

Updated by Milos Koscica over 9 years ago

Thank you for the recommended fixes, those did work we were able to greatly reduce the time it takes to complete those 9.5 transformations.

We are still however seeing a difference that is big enough to warranty further investigation.

Are there any other updates we could make to the code to further make these numbers be closer?

Latest i2a.xsl and latest results excel uploaded.

Actions #6

Updated by Michael Kay over 9 years ago

  • Found in version set to 9.5
  • Fixed in version set to 9.6.0.1

I've just been checking on the status of this. It seems that it was fully resolved in the 9.6 branch. However, the attempt to patch 9.5 to optimize pattern predicates led to regression elsewhere in the system, and was abandoned. So the problem remains unresolved on 9.5. However, 9.5 is being managed for stability and any patch that is only for performance improvements has to be srutinized very carefully, so it's probably best to leave things this way.

Actions #7

Updated by O'Neil Delpratt over 9 years ago

  • Status changed from Resolved to Closed

Closing this bug according to comment 6. Bug fixed in Saxon 9.6.0.1

Actions #8

Updated by O'Neil Delpratt over 8 years ago

  • Applies to branch 9.5, 9.6 added
  • Fix Committed on Branch 9.6 added

Please register to edit this issue

Also available in: Atom PDF