| Bug #48631 | Performance schema: unit test failures | ||
|---|---|---|---|
| Submitted: | 9 Nov 2009 9:26 | Modified: | 14 Jan 2010 18:08 |
| Reporter: | Guilhem Bichot | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Performance Schema | Severity: | S3 (Non-critical) |
| Version: | mysql-trunk-perfschema | OS: | Any |
| Assigned to: | Marc ALFF | CPU Architecture: | Any |
[9 Nov 2009 9:26]
Guilhem Bichot
[9 Nov 2009 20:34]
Guilhem Bichot
Olav Sandstaa was kind enough to run on Solaris: Solaris 10 64-bit on AMD/x86 : ../storage/perfschema/unittest/pfs_timer-t.............FAILED tests 3, 6, 9 64 bit SPARC: ./storage/perfschema/unittest/pfs_timer-t.............FAILED tests 3, 6, 9 ../storage/perfschema/unittest/pfs_instr-t.............FAILED test 2 mysys unit tests work.
[9 Nov 2009 21:56]
Marc ALFF
I can not reproduce the failures on my Linux 64 bit machine
malff@linux-su11:perfschema> make test
perl ../../unittest/unit.pl run unittest
Running tests: unittest
unittest/pfs_instr-oom-t.........ok
unittest/pfs_instr-t.............ok
unittest/pfs_instr_class-oom-t...ok
unittest/pfs_timer-t.............ok
3/11 skipped: various reasons
unittest/pfs_instr_class-t.......ok
unittest/pfs-t...................ok
All tests successful, 3 subtests skipped.
Files=6, Tests=476, 6 wallclock secs ( 0.29 cusr + 0.53 csys = 0.82 CPU)
malff@linux-su11:perfschema> cd unittest/
malff@linux-su11:unittest> ./pfs_timer-t
1..11
# cycle a: 1089358
# nano a: 0
# micro a: 1000000
# milli a: 0
# tick a: 0
# cycle b: 5004269747150
# nano b: 0
# micro b: 5004010000000
# milli b: 4830115828860
# tick b: 4587155963500
# cycle b-a: 5004268657792
# nano b-a: 0
# micro b-a: 5004009000000
# milli b-a: 4830115828860
# tick b-a: 4587155963500
ok 1 - cycle timer ascending
ok 2 - cycle timer count >= low limit
ok 3 - cycle timer count <= high limit
ok 4 # skip nano timer not implemented
ok 5 # skip nano timer not implemented
ok 6 # skip nano timer not implemented
ok 7 - micro timer ascending
ok 8 - micro timer count >= low limit
ok 9 - micro timer count <= high limit
ok 10 - milli timer ascending
ok 11 - tick timer ascending
When a test fails, please run it alone, and capture the test output (see example above):
- for the timer test, all the timer values are printed in '#' comments, so we will see if the values
- for the crash, at least we will see where the crash occurs.
A crash can happen if a previous test failed (say, a pointer was expected but
the code got a NULL, and the pointer is used in a later test.
The unit test code is not testing for every error conditions, and therefore is not crash safe, but at least is is validating previous conditions with a ok(),
so the first deviation between the actual and expected run should be reported.
Note that the timer test assumes that sleep() actually works, which may not
be the case since sleep() can be interrupted, take more time depending on the machine load, etc, so idea of automating the timer tests might have to be simply abandoned.
[9 Nov 2009 21:58]
Marc ALFF
I wish previous entries could be edited. Correction: "so we will see if the values" ... are close or not.
[9 Nov 2009 22:09]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/89865 2950 Marc Alff 2009-11-09 Bug#48631 Performance schema: unit test failures Cleanup of the timer unit test. Avoid including the overhead of timer X in the measure of timer Y.
[9 Nov 2009 22:12]
Guilhem Bichot
Linux 64-bit: [INS 23:10 /m/bzrrepos/mysql-trunk-perfschema/storage/perfschema/unittest $] ./pfs_instr-t 1..102 ok 1 - zero init ok 2 - no instances init ok 3 - no mutex ok 4 - lost 1 ok 5 - no mutex ok 6 - lost 2 ok 7 - no rwlock ok 8 - lost 1 ok 9 - no rwlock ok 10 - lost 2 ok 11 - no cond ok 12 - lost 1 ok 13 - no cond ok 14 - lost 2 ok 15 - no thread ok 16 - lost 1 ok 17 - no thread ok 18 - lost 2 ok 19 - no file ok 20 - lost 1 ok 21 - no file ok 22 - lost 2 ok 23 - no file ok 24 - lost 3 ok 25 - no file ok 26 - lost 4 ok 27 - no file ok 28 - lost 5 ok 29 - no table ok 30 - lost 1 ok 31 - no table ok 32 - lost 2 not ok 33 - instances init ok 34 - mutex ok 35 - not lost ok 36 - mutex ok 37 - not lost ok 38 - no mutex ok 39 - lost 1 ok 40 - mutex ok 41 - no new loss ok 42 - rwlock ok 43 - not lost ok 44 - rwlock ok 45 - not lost ok 46 - no rwlock ok 47 - lost 1 ok 48 - rwlock ok 49 - no new loss ok 50 - cond ok 51 - not lost ok 52 - cond ok 53 - not lost ok 54 - no cond ok 55 - lost 1 ok 56 - cond ok 57 - no new loss Bail out! Signal 11 thrown (note a "not ok" at test 33). [INS 23:10 /m/bzrrepos/mysql-trunk-perfschema/storage/perfschema/unittest $] ./pfs_timer-t 1..11 # cycle a: 5188378 # nano a: 0 # micro a: 5000000 # milli a: 0 # tick a: 0 # cycle b: 508309371219 # nano b: 0 # micro b: 5000075000000 # milli b: 5045408680000 # tick b: 4807692307500 # cycle b-a: 508304182841 # nano b-a: 0 # micro b-a: 5000070000000 # milli b-a: 5045408680000 # tick b-a: 4807692307500 ok 1 - cycle timer ascending not ok 2 - cycle timer count >= low limit ok 3 - cycle timer count <= high limit ok 4 # skip nano timer not implemented ok 5 # skip nano timer not implemented ok 6 # skip nano timer not implemented ok 7 - micro timer ascending ok 8 - micro timer count >= low limit ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending I have marc.alff@sun.com-20091106221733-y2vduzzwhiv3evnp, built with BUILD/compile-pentium64-valgrind-max .
[9 Nov 2009 22:23]
Guilhem Bichot
re-checked pfs_timer-t with the latest fix :marc.alff@sun.com-20091109220645-lwpx25zsibd0o40y : still 1..11 # cycle a: 5423665 # nano a: 0 # micro a: 10000096000000 # milli a: 14409221895000 # tick a: 18348623854000 # cycle b: 361290815717 # nano b: 0 # micro b: 15000071000000 # milli b: 19212295860000 # tick b: 22935779817500 # cycle b-a: 361285392052 # nano b-a: 0 # micro b-a: 4999975000000 # milli b-a: 4803073965000 # tick b-a: 4587155963500 ok 1 - cycle timer ascending not ok 2 - cycle timer count >= low limit ok 3 - cycle timer count <= high limit ok 4 # skip nano timer not implemented ok 5 # skip nano timer not implemented ok 6 # skip nano timer not implemented ok 7 - micro timer ascending ok 8 - micro timer count >= low limit ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending
[9 Nov 2009 22:44]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/89874 2951 Marc Alff 2009-11-09 Bug#48631 Performance schema: unit test failures Added the missing initialization of param.m_file_handle_sizing, which would cause random unit test failures (init failed with OOM, because a random size is used to allocate memory).
[9 Nov 2009 22:53]
Marc ALFF
Thanks for the fast feed back. I think the crash caused by a failed init_instruments() is now fixed, an init parameter was missing (see the second patch). As for failures of the CYCLE timer, which is too low: not ok 2 - cycle timer count >= low limit this is highly platform dependent. Please indicate: - what is the OS used - what is the processor speed - if the OS is configured to change the processor speed depending on the load (CPU Freq governors on Linux) and please indicate if the test consistently fails, some times passes or fails, and if the results depend on the machine load or not, etc. Any detail that you think is relevant would help. I don't know how valgrind works internally, and if it samples things (which imply a timer or interruptions somewhere), but I would *not* use a valgrind build for this sort of tests.
[9 Nov 2009 23:32]
Marc ALFF
Another important data is the result of the my_rdtsc-t test: malff@linux-su11:mysys> ./my_rdtsc-t 1..11 # ----- Routine --------------- # myt.cycles.routine : 2 # myt.nanoseconds.routine : 0 # myt.microseconds.routine : 13 # myt.milliseconds.routine : 18 # myt.ticks.routine : 17 # ----- Frequency ------------- # myt.cycles.frequency : 2830542288 # myt.nanoseconds.frequency : 0 # myt.microseconds.frequency : 1000000 # myt.milliseconds.frequency : 1037 # myt.ticks.frequency : 109 # ----- Resolution ------------ # myt.cycles.resolution : 1 # myt.nanoseconds.resolution : 0 # myt.microseconds.resolution : 1 # myt.milliseconds.resolution : 1 # myt.ticks.resolution : 1 # ----- Overhead -------------- # myt.cycles.overhead : 60 # myt.nanoseconds.overhead : 0 # myt.microseconds.overhead : 170 # myt.milliseconds.overhead : 196 # myt.ticks.overhead : 646 ok 1 - my_timer_init() did not crash ok 2 - The cycle timer is strictly increasing ok 3 - The cycle timer is implemented ok 4 - The nanosecond timer is increasing ok 5 - The nanosecond timer is not implemented and returns 0 ok 6 - The microsecond timer is increasing ok 7 - The microsecond timer is implemented ok 8 - The millisecond timer is increasing ok 9 - The millisecond timer is implemented ok 10 - The tick timer is increasing ok 11 - The tick timer is implemented This will show the routine / frequency / etc seen by the timer code for the failing CYCLE timer.
[10 Nov 2009 9:28]
Olav Sandstå
In case it can be of any use: Here is the output from running the pfs_timer-t test on Solaris 10 on a 64-bit AMD server: os136802@fimafeng08:~/<5>perfschema/unittest> ./pfs_timer-t 1..11 # cycle a: 10931191 # nano a: 5009897563000 # micro a: 10019773000000 # milli a: 14521739132250 # tick a: 18728971963572 # cycle b: 5022607931778 # nano b: 10019772483000 # micro b: 15029656000000 # milli b: 19362318843000 # tick b: 23411214954465 # cycle b-a: 5022597000587 # nano b-a: 5009874920000 # micro b-a: 5009883000000 # milli b-a: 4840579710750 # tick b-a: 4682242990893 ok 1 - cycle timer ascending ok 2 - cycle timer count >= low limit not ok 3 - cycle timer count <= high limit ok 4 - nano timer ascending ok 5 - nano timer count >= low limit not ok 6 - nano timer count <= high limit ok 7 - micro timer ascending ok 8 - micro timer count >= low limit not ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending The test is done after having updated to the currently latest source version from mysql-trunk-perfschema.
[10 Nov 2009 13:32]
Guilhem Bichot
I pulled the latest tree.
pfs_instr-t passes. In the rest of this post I talk about pfs_timer-t.
My build is compile-pentium64-valgrind-max, which just means that safemalloc is disabled and certain superfluous variable initializations are off (see LINT_INIT()), otherwise it's a debug build. I'm not running the test under Valgrind (not doing "valgrind pfs_timer-t"), so Valgrind isn't involved.
My computer is a laptop with variable CPU frequency.
I ran the tests 20 times in a loop.
First 20 times, CPU was not loaded (a few %, and /proc/cpuinfo reported "1GHz"). Second 20 times, I loaded it 100% with some other job (cpuinfo said 2.16GHz which is the max frequency of the CPU).
I'm attaching results of the first 20 times ("linux_not_loaded.txt") and second 20 times ("linux_loaded.txt"). I don't see a pattern: subtests 2 and 3 fail, not always... Looks difficult...
Linux 64-bit Ubuntu 8.10, laptop, 2-core 2.16GHz.
[10 Nov 2009 13:34]
Guilhem Bichot
test output, CPU not loaded
Attachment: linux_not_loaded.txt (text/plain), 16.83 KiB.
[10 Nov 2009 13:35]
Guilhem Bichot
test output, CPU 100% loaded
Attachment: linux_loaded.txt (text/plain), 16.90 KiB.
[11 Nov 2009 9:46]
Olav Sandstå
After updating to the latest source version the pfs_instr-t test that failed earlier when running on 64 bit SPARC does no longer fail. The only failures reported on 64 bit SPARC are now: ../storage/perfschema/unittest/pfs_timer-t.............FAILED tests 3, 6, 9
[11 Nov 2009 9:55]
Olav Sandstå
Here are new test results from running the pfs_timer-t test on Solaris 10 on an AMD and a SPARC server. Solaris 10 64-bit on dual CPU/dual core AMD Opteron Processor 2220 (2.8 GHz) ============================================================================ 1..11 # cycle a: 15882878 # nano a: 5009920193000 # micro a: 10019819000000 # milli a: 14521739132250 # tick a: 18385321101708 # cycle b: 5022604294031 # nano b: 10019818867000 # micro b: 15029716000000 # milli b: 19361352659425 # tick b: 22981651377135 # cycle b-a: 5022588411153 # nano b-a: 5009898674000 # micro b-a: 5009897000000 # milli b-a: 4839613527175 # tick b-a: 4596330275427 ok 1 - cycle timer ascending ok 2 - cycle timer count >= low limit not ok 3 - cycle timer count <= high limit ok 4 - nano timer ascending ok 5 - nano timer count >= low limit not ok 6 - nano timer count <= high limit ok 7 - micro timer ascending ok 8 - micro timer count >= low limit not ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending Solaris 10 64-bit on a dual CPU UltraSPARC-IIIi cpu (1.3 GHz) ============================================================= 1..11 # cycle a: 108159408 # nano a: 5010117412000 # micro a: 10020057000000 # milli a: 14535783359640 # tick a: 18728971963572 # cycle b: 5029223120656 # nano b: 10020055991000 # micro b: 15030067000000 # milli b: 19381044479520 # tick b: 23411214954465 # cycle b-a: 5029114961248 # nano b-a: 5009938579000 # micro b-a: 5010010000000 # milli b-a: 4845261119880 # tick b-a: 4682242990893 ok 1 - cycle timer ascending ok 2 - cycle timer count >= low limit not ok 3 - cycle timer count <= high limit ok 4 - nano timer ascending ok 5 - nano timer count >= low limit not ok 6 - nano timer count <= high limit ok 7 - micro timer ascending ok 8 - micro timer count >= low limit not ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending Note: On the AMD server test 3, 6, 9 fails on every run while on the SPARC machine, only test 3 fails on every run. Test 6 and 9 fails/passes "randomly".
[11 Nov 2009 14:21]
Guilhem Bichot
Interesting, in all Olav's results, "tick" is the worse (8% wrong sometimes), then "milli". "tick" is bad in my results too. What's wrong with "tick"...?
[11 Nov 2009 15:00]
Peter Gulutzan
> Interesting, in all Olav's results, "tick" is the worse (8% wrong sometimes), > then "milli". "tick" is bad in my results too. What's wrong with "tick"...? From the WL#2360 description (probably a few years old now): "What Peter has seen so far is: TICK has high overhead as well as low frequency so it looks like a bad choice on all platforms that we support. (This surprises him greatly; he can't explain the numbers that he gets.) So far we haven't found a use for ticks, but initially we want all possibilities to be there. If no user reports a case where it's worthwhile, we'll remove the TICK row for GA." For timings on other platforms, see rdtsc3_notes.txt attached to WL#2373.
[12 Nov 2009 8:39]
Guilhem Bichot
3 runs on Windows, latest revision marc.alff@sun.com-20091109224146-1e6af3x4f9swzze5 : 1..11 # cycle a: 3783101 # nano a: 0 # micro a: 10015170346144 # milli a: 14385057469308 # tick a: 19278152077240 # cycle b: 4937143466948 # nano b: 0 # micro b: 15022761665224 # milli b: 19180076625744 # tick b: 24098171328504 # cycle b-a: 4937139683847 # nano b-a: 0 # micro b-a: 5007591319080 # milli b-a: 4795019156436 # tick b-a: 4820019251264 ok 1 - cycle timer ascending not ok 2 - cycle timer count >= low limit ok 3 - cycle timer count <= high limit ok 4 # skip nano timer not implemented ok 5 # skip nano timer not implemented ok 6 # skip nano timer not implemented ok 7 - micro timer ascending ok 8 - micro timer count >= low limit not ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending 1..11 # cycle a: 4373600 # nano a: 0 # micro a: 10015194930176 # milli a: 14482160072772 # tick a: 19352657007250 # cycle b: 4965136999130 # nano b: 0 # micro b: 15022791207967 # milli b: 19309546763696 # tick b: 24191304350850 # cycle b-a: 4965132625530 # nano b-a: 0 # micro b-a: 5007596277791 # milli b-a: 4827386690924 # tick b-a: 4838647343600 ok 1 - cycle timer ascending not ok 2 - cycle timer count >= low limit ok 3 - cycle timer count <= high limit ok 4 # skip nano timer not implemented ok 5 # skip nano timer not implemented ok 6 # skip nano timer not implemented ok 7 - micro timer ascending ok 8 - micro timer count >= low limit not ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending 1..11 # cycle a: 4118352 # nano a: 0 # micro a: 10015152397007 # milli a: 14553294572712 # tick a: 20800623049569 # cycle b: 4993083732294 # nano b: 0 # micro b: 15022743157359 # milli b: 19404069766200 # tick b: 25999999995762 # cycle b-a: 4993079613942 # nano b-a: 0 # micro b-a: 5007590760352 # milli b-a: 4850775193488 # tick b-a: 5199376946193 ok 1 - cycle timer ascending not ok 2 - cycle timer count >= low limit ok 3 - cycle timer count <= high limit ok 4 # skip nano timer not implemented ok 5 # skip nano timer not implemented ok 6 # skip nano timer not implemented ok 7 - micro timer ascending ok 8 - micro timer count >= low limit not ok 9 - micro timer count <= high limit ok 10 - milli timer ascending ok 11 - tick timer ascending Differences are all around 5 seconds, and too inaccurate for the test's criteria. This is a server-class machine, unlikely to have varying CPU speed.
[12 Nov 2009 9:10]
Guilhem Bichot
Hello Peter. Thanks for the pointers. I see in WL#2360 "A tick is the time between processor interrupts. It's been 1/100 second for a long time". If it's still 1/100 second: pfs_timer-t expects to find 5 seconds +- a relative error of 1/1000: if the tick is 1/100 second, 1/100 / 5 = 1/500, a relative error which is twice bigger than 1/1000 which can already explain why the test fails.
[12 Nov 2009 9:39]
Guilhem Bichot
Server-class machine, Linux 64-bit.
1..11
# cycle a: 1741509
# nano a: 0
# micro a: 9999026000000
# milli a: 14491787441425
# tick a: 18348623854000
# cycle b: 5012378137746
# nano b: 0
# micro b: 14999026000000
# milli b: 19322705316425
# tick b: 22935779817500
# cycle b-a: 5012376396237
# nano b-a: 0
# micro b-a: 5000000000000
# milli b-a: 4830917875000
# tick b-a: 4587155963500
ok 1 - cycle timer ascending
ok 2 - cycle timer count >= low limit
not ok 3 - cycle timer count <= high limit
ok 4 # skip nano timer not implemented
ok 5 # skip nano timer not implemented
ok 6 # skip nano timer not implemented
ok 7 - micro timer ascending
ok 8 - micro timer count >= low limit
ok 9 - micro timer count <= high limit
ok 10 - milli timer ascending
ok 11 - tick timer ascending
1..11
# cycle a: 1907367
# nano a: 0
# micro a: 9999016000000
# milli a: 14491787441425
# tick a: 19801980198000
# cycle b: 5012375903689
# nano b: 0
# micro b: 14999019000000
# milli b: 19322705316425
# tick b: 24752475247500
# cycle b-a: 5012373996322
# nano b-a: 0
# micro b-a: 5000003000000
# milli b-a: 4830917875000
# tick b-a: 4950495049500
ok 1 - cycle timer ascending
ok 2 - cycle timer count >= low limit
not ok 3 - cycle timer count <= high limit
ok 4 # skip nano timer not implemented
ok 5 # skip nano timer not implemented
ok 6 # skip nano timer not implemented
ok 7 - micro timer ascending
ok 8 - micro timer count >= low limit
ok 9 - micro timer count <= high limit
ok 10 - milli timer ascending
ok 11 - tick timer ascending
1..11
# cycle a: 1992809
# nano a: 0
# micro a: 9998520000000
# milli a: 14477799224035
# tick a: 18867924528000
# cycle b: 5011863915121
# nano b: 0
# micro b: 14998511000000
# milli b: 19304054049035
# tick b: 23584905660000
# cycle b-a: 5011861922312
# nano b-a: 0
# micro b-a: 4999991000000
# milli b-a: 4826254825000
# tick b-a: 4716981132000
ok 1 - cycle timer ascending
ok 2 - cycle timer count >= low limit
not ok 3 - cycle timer count <= high limit
ok 4 # skip nano timer not implemented
ok 5 # skip nano timer not implemented
ok 6 # skip nano timer not implemented
ok 7 - micro timer ascending
ok 8 - micro timer count >= low limit
ok 9 - micro timer count <= high limit
ok 10 - milli timer ascending
ok 11 - tick timer ascending
The above was when the machine is not loaded. When it's loaded to 100% of both CPUs:
1..11
# cycle a: 8672363
# nano a: 0
# micro a: 9999997000000
# milli a: 14492753625000
# tick a: 21063157893789
# cycle b: 5013366206625
# nano b: 0
# micro b: 14999996000000
# milli b: 19323671500000
# tick b: 26326315788289
# cycle b-a: 5013357534262
# nano b-a: 0
# micro b-a: 4999999000000
# milli b-a: 4830917875000
# tick b-a: 5263157894500
ok 1 - cycle timer ascending
ok 2 - cycle timer count >= low limit
not ok 3 - cycle timer count <= high limit
ok 4 # skip nano timer not implemented
ok 5 # skip nano timer not implemented
ok 6 # skip nano timer not implemented
ok 7 - micro timer ascending
ok 8 - micro timer count >= low limit
ok 9 - micro timer count <= high limit
ok 10 - milli timer ascending
ok 11 - tick timer ascending
1..11
# cycle a: 7139433
# nano a: 0
# micro a: 10000024000000
# milli a: 14492753625000
# tick a: 20202020202000
# cycle b: 5013382558716
# nano b: 0
# micro b: 15000022000000
# milli b: 19323671500000
# tick b: 25252525252500
# cycle b-a: 5013375419283
# nano b-a: 0
# micro b-a: 4999998000000
# milli b-a: 4830917875000
# tick b-a: 5050505050500
ok 1 - cycle timer ascending
ok 2 - cycle timer count >= low limit
not ok 3 - cycle timer count <= high limit
ok 4 # skip nano timer not implemented
ok 5 # skip nano timer not implemented
ok 6 # skip nano timer not implemented
ok 7 - micro timer ascending
ok 8 - micro timer count >= low limit
ok 9 - micro timer count <= high limit
ok 10 - milli timer ascending
ok 11 - tick timer ascending
1..11
# cycle a: 7795326
# nano a: 0
# micro a: 10003526000000
# milli a: 14496618359300
# tick a: 18691588786000
# cycle b: 5016895406026
# nano b: 0
# micro b: 15003527000000
# milli b: 19327536234300
# tick b: 23364485982500
# cycle b-a: 5016887610700
# nano b-a: 0
# micro b-a: 5000001000000
# milli b-a: 4830917875000
# tick b-a: 4672897196500
ok 1 - cycle timer ascending
ok 2 - cycle timer count >= low limit
not ok 3 - cycle timer count <= high limit
ok 4 # skip nano timer not implemented
ok 5 # skip nano timer not implemented
ok 6 # skip nano timer not implemented
ok 7 - micro timer ascending
ok 8 - micro timer count >= low limit
ok 9 - micro timer count <= high limit
ok 10 - milli timer ascending
ok 11 - tick timer ascending
Again, results are sensible (all around 5 seconds) with an error margin higher than the test's criteria.
The test works like this:
x= current cycle counter;
my_sleep(5 seconds);
y= current cycle counter;
verify that that (y-x)/cpu_frequency is equal to 5 seconds with at most 1/1000th error.
Here are different points which Marc and I have analyzed:
- If the machine is loaded, it is possible that my_sleep() takes a bit more than 5 seconds to return.
- my_sleep() itself is maybe not very accurate (it's implemented with select() on Linux at least), so maybe in practice it's just impossible to expect it will return in 5 secs +- 1/1000.
- if the machine is a laptop, there can be variable-frequency problems; a quick test on mine shows that the frequency (according to /proc/cpuinfo) goes down from 2GHz to 1 GHz during a sleep of 5 seconds.
Marc's suggestion is that the criteria should be removed from the test, only the printouts ("b-a") should be left. The test becomes then a non-test, only informative.
I agree with that, I don't see a better solution which will be robust on all machine.
[17 Nov 2009 15:17]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/90681 2957 Marc Alff 2009-11-17 Bug#48631 Performance schema: unit test failures Simplified the unit test, some parts can not be automated.
[18 Nov 2009 15:39]
Marc ALFF
Queued in mysql-trunk-perfschema
[14 Jan 2010 10:06]
Marc ALFF
Merged in: - mysql-next-mr (Celosia / 5.5.99-m3) - mysql-6.0-codebase (6.0.14)
[14 Jan 2010 18:08]
Paul DuBois
Not in any released version. No changelog entry needed.
