Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[6.x.x] New exist:time XQuery Pragma #5077

Merged
merged 3 commits into from
Oct 6, 2023

Conversation

adamretter
Copy link
Contributor

@adamretter adamretter commented Oct 4, 2023

Backported from FusionDB - A new XQuery Pragma called exist:time that is backwards compatible with the previous limited exist:timer pragma.

Like its predecessor exist:timer it can be used for timing an XQuery expression. However, its main advantage is that it can also be used to log multiple iterations of the same expression using the parameter measurement-mode=multiple. In addition to that the new exist:time pragma also adds:

  1. Nanosecond precision (useful for measuring very fast expressions or multiple iterations thereof)
  2. A humane format output of the total time elapsed.
  3. Automatically adapts output between ns and ms units depending on the magnitude of the measurement
  4. A logging-level parameter so that you may set the log-level dynamically on invocation.
  5. Alog-message-prefix so that you may specify a prefix to be appended to the log message; this can make it much easier for you when trying to locate specific log messages.

Example 1 - Single measurement

(# exist:time logging-level=INFO #) {
    doc("/db/hindawi-example.xml")//p
}

produces log output like:

Elapsed: 21 ms.

Example 2 - Single iteration measurements inside FLWOR

for $i in (1 to 2)
return
  (# exist:time logging-level=INFO #) {
      $i * 10
  }

produces log output like:

Elapsed: 35967 ns.
Elapsed: 18028 ns.

Example 3 - Multiple iteration measurement inside FLWOR

This new facility is extremely useful for helping diagnose performance issues when you have a loop that is slow, but the expressions inside the loop itself appear fast. In such a scenario you can use exist:time to measure the performance of one or more expressions within the loop.

for $i in (1 to 2)
return
  (# exist:time logging-level=INFO measurement-mode=multiple #) {
      $i * 10
  }

produces log output like:

Elapsed: 53995 ns (53995 ns) [iterations=2 first=35967 ns, min=18028 ns, avg=26997.50 ns, max=35967 ns, last=18028 ns].

@adamretter adamretter added the enhancement new features, suggestions, etc. label Oct 4, 2023
@adamretter adamretter added this to the eXist-6.2.1 milestone Oct 4, 2023
@adamretter adamretter force-pushed the 6.x.x/feat/time-pragma branch 3 times, most recently from 26ef01f to 3570158 Compare October 5, 2023 06:15
Copy link
Member

@dizzzz dizzzz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

builds are not clean, rebase needed?

@adamretter
Copy link
Contributor Author

@dizzzz The build errors are unrelated, they are from downloading the NVE CVE database.

…lect its purpose. Leaves 'exist:timer' as an intact legacy supported name for now too
@dizzzz dizzzz merged commit 5818c56 into eXist-db:develop-6.x.x Oct 6, 2023
5 of 14 checks passed
@adamretter adamretter deleted the 6.x.x/feat/time-pragma branch November 28, 2024 20:54
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement new features, suggestions, etc.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants