qp_stem_scale1 sometimes fails on Windows

[Charlie Hull]

About once every three runs I get

Running test: qp_stem_scale1...
defflags: small=0s, large=0.016s
.\queryparsertest.cc:1802: ((time2) < (time1 * 2))
Expected `time2' to be less than than `time1 * 2': were 0.016 and 0
 FAILED

and once I got

defflags: small=0.016s, large=0.015s
synflags: small=0.016s, large=0s
synflags: small=0.015s, large=0.032s
 FAILED

Looks like another granularity issue.

[Olly Betts]

Yes. Interestingly, the granularity isn't 1 second as at least I had assumed, but 0.015 or 0.016 seocnds.

Can you try the patch I'll attach shortly (with branches/1.0)?

[Olly Betts]

Backported patch

[Charlie Hull]

I've applied the patch manually to the latest version and unfortunately I'm still getting occasional failures:

C:\work\xapian\branch\1.0\xapian-core\tests>queryparsertest qp_stem_scale1
Running test: qp_stem_scale1...
defflags: small=0.016s, large=0.015s
synflags: small=0.016s, large=0.016s
synflags: small=0.015s, large=0.032s
 FAILED

C:\work\xapian\branch\1.0\xapian-core\tests>queryparsertest qp_stem_scale1
Running test: qp_stem_scale1... ok

C:\work\xapian\branch\1.0\xapian-core\tests>queryparsertest qp_stem_scale1
Running test: qp_stem_scale1... ok

C:\work\xapian\branch\1.0\xapian-core\tests>queryparsertest qp_stem_scale1
Running test: qp_stem_scale1... SKIPPED

C:\work\xapian\branch\1.0\xapian-core\tests>queryparsertest qp_stem_scale1
Running test: qp_stem_scale1... ok

C:\work\xapian\branch\1.0\xapian-core\tests>queryparsertest qp_stem_scale1
Running test: qp_stem_scale1...
defflags: small=0.016s, large=0.016s
synflags: small=0s, large=0.015s
 FAILED

[Olly Betts]

Sorry, I patched in a hurry before and only did this for the first subtest.

Please try the updated patch I'll attach shortly.

[Olly Betts]

updated patch

[Charlie Hull]

Unfortunately still failing occasionally (1 in 20 or so):

Running test: qp_stem_scale1...
defflags: small=0.016s, large=0.016s
synflags: small=0.015s, large=0.016s
synflags: small=0.015s, large=0.032s
.\queryparsertest.cc:1826: ((time2) < (time1 * 2))
Expected `time2' to be less than than `time1 * 2': were 0.032 and 0.03

 FAILED

[Olly Betts]

OK, this is now a different issue. The "small" run takes just less than two ticks, and the "large" run just more.

Using <= doesn't help us here, as it seems the "tick" interval is something like 1/64 of a second, and so gets rounded when expressed in thousands of a second. So we either get 0.015 or 0.016 for the interval between ticks when these rounded times are subtracted, and 0.031 isn't < 0.015 * 2 so we can still fail.

If we could easily read the clock resolution, we could address this. Otherwise, I'm not quite sure how best to address this. We could use (time2 < time1 * 2.14) but that's kind of arbitrary...

Making the test just take longer helps for current systems, but at some point computers will get fast enough that we'll hit these issues again.

For 1.0.9, I'm leaning towards applying the latest patch here (which helps reduce how often this test fails) and just documenting the issue, but thoughts welcome.

[Charlie Hull]

I know 1.0.9 is close, so I'd vote for applying the patch and documenting occasional failures.

[Olly Betts]

Applied qp-skip-for-poor-timer-granularity2.patch for 1.0.9, updating milestone to 1.0.10.

[Olly Betts]

My feeling is that fixing this better is more appropriate for trunk, and it's not critical for the 1.1.0 release, so marking as milestone:1.1.1 for now.

[Olly Betts]

SVN trunk now uses CPU time not wall clock time where it can (which is essentially "everywhere but Microsoft Windows") which helps avoid sporadic failures of these timing tests due to load spikes. Also, if the testsuite times a test at 0 seconds, it will increase the number of repetitions by a factor of 10 and rerun it until it can measure a time (or the number of repetitions overflows as a safety valve!)

Fixed this particular issue in trunk r12580 by bumping the factor to 2.15 as I couldn't see a better way.

[Olly Betts]

Backported for 1.0.13 in r12730.