Hi,
If you can run MS-Windows without virtual machine, please visit testbot https://testbot.winehq.org/JobDetails.pl?Key=17175 download the 32 or 64bit executable and execute it.
I can't really trust vm machines for timing, but so far it appears that:
- Vista/w2k8SE/w7 perform rate correction so as to maintain an average number of callbacks sync.c:583: TimerQueue period 10ms with 0 stress, flags 0 sync.c:558: thread 1340 hpctime 30 delta 15 sync.c:558: thread 1340 hpctime 46 delta 16 sync.c:558: thread 1340 hpctime 46 delta 0 sync.c:601: 80 callbacks within 796/800ms, avg 9.950/10
They'll refire with up to 0 wait upon noticing that it's very late!
sync.c:583: TimerQueue period 10ms with 7 stress, flags 10 sync.c:558: thread 1340 hpctime 46 delta 15 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 53 delta 7 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 62 delta 9 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 77 delta 15 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 84 delta 7 sync.c:570: thread 1340 busy 7ms sync.c:601: 59 callbacks within 607/600ms, avg 10.288/10
It maintains its average even the callback is busy for 7ms within each 10ms interval.
sync.c:583: TimerQueue period 10ms with 12 stress, flags 20 sync.c:558: thread 828 hpctime 31 delta 12 sync.c:570: thread 828 busy 12ms sync.c:558: thread 828 hpctime 43 delta 12 sync.c:570: thread 828 busy 12ms sync.c:601: 42 callbacks within 507/400ms, avg 12.071/10
This one surprises me. No multiple threads are used. Wine uses several threads here. When every callback is busy for 12ms, MS does not reach an average 10ms per invocation, whereas Wine does, thanks to several threads that execute the callbacks concurrently.
I want to figure out why several threads were not used.
sync.c:601: 40 callbacks within 4624/4680ms, avg 115.600/117 Ok. Note that the average is usually slightly lower than expected, simply because the first callback is asked to fire at time period/2.
- w2k/xp do not maintain an average (at least on testbot) sync.c:583: TimerQueue period 10ms with 0 stress, flags 0 sync.c:558: thread 836 hpctime 30 delta 15 sync.c:558: thread 836 hpctime 46 delta 16 sync.c:601: 51 callbacks within 796/800ms, avg 15.608/10
So at least in testbot, the minimum rate is the well-known 15.625ms interval. Note that the 15.625ms is visible in the w7 testbot results too.
sync.c:583: TimerQueue period 117ms with 0 stress, flags 20 sync.c:558: thread 840 hpctime 311 delta 125 sync.c:558: thread 840 hpctime 436 delta 125 sync.c:601: 37 callbacks within 4561/4680ms, avg 123.270/117
Unlike w7, it never corrects to a smaller interval like 109ms to reach the requested average of 117ms.
This is good news for audio in Wine, because we can make CreateTimerQueue mimic Vista/w2k8/w7 behaviour to give us a stable rate (on average).
The logs are quite long, you can send me them per e-mail.
Thank you, Jörg Höhle
Hi,
thank you. The 2 answers I received so far already highlight the astonishing differences among native w7 systems:
One machine manages to invoke callbacks at the exact rate I requested (10, 22, 117): sync.c:558: thread 13316 hpctime 664 delta 10 sync.c:558: thread 13316 hpctime 296 delta 22 sync.c:558: thread 13316 hpctime 642 delta 117 and shows the useage of several threads when the callbacks is too busy: sync.c:558: thread 17404 hpctime 374 delta 10 sync.c:570: thread 11912 busy 12ms sync.c:558: thread 11912 hpctime 384 delta 10 sync.c:570: thread 17404 busy 12ms sync.c:558: thread 17404 hpctime 394 delta 10 sync.c:570: thread 11912 busy 12ms
Another machine only knows 15.625ms intervals: sync.c:583: TimerQueue period 10ms with 0 stress, flags 0 sync.c:558: thread 5512 hpctime 15 delta 15 sync.c:558: thread 5252 hpctime 15 delta 0 sync.c:558: thread 5512 hpctime 30 delta 15 sync.c:558: thread 5252 hpctime 46 delta 16 sync.c:558: thread 5512 hpctime 46 delta 0 sync.c:558: thread 5512 hpctime 61 delta 15 sync.c:558: thread 5512 hpctime 77 delta 16 sync.c:558: thread 5252 hpctime 77 delta 0 or when asked for a 117ms period: sync.c:558: thread 5252 hpctime 529 delta 109 sync.c:558: thread 5252 hpctime 654 delta 125 and struggles with more threads due to the irregularities: sync.c:558: thread 5252 hpctime 0 delta 0 sync.c:558: thread 6088 hpctime 0 delta 0 sync.c:570: thread 6088 busy 7ms sync.c:570: thread 5252 busy 7ms sync.c:558: thread 5252 hpctime 16 delta 16 sync.c:570: thread 5252 busy 7ms sync.c:558: thread 5252 hpctime 31 delta 15 sync.c:558: thread 6088 hpctime 31 delta 0 sync.c:570: thread 5252 busy 7ms sync.c:570: thread 6088 busy 7ms yet the average result is ok: sync.c:601: 61 callbacks within 593/600ms, avg 9.721/10
Thank you guys, I don't need more tests. I think I've made my point. CreateTimerQueue ought to be changed.
Regards, Jörg Höhle
On 03/06/2012 06:33 AM, Joerg-Cyril.Hoehle@t-systems.com wrote:
Hi,
thank you. The 2 answers I received so far already highlight the astonishing differences among native w7 systems:
Have you used timeBeginPeriod() in your tests? From long time ago Win NT supported up to 10ms call back intervals, but only guaranteed if you set time "precision" with timeBeginPeriod() to less then or equal to your period.
Vitaliy
Vitaliy Margolen wrote:
Have you used timeBeginPeriod() in your tests?
No, since the test isn't using winmm at all, it didn't strike me that this might have an influence.
Regards, Jörg Höhle
Hey Joerg,
Op 06-03-12 11:21, Joerg-Cyril.Hoehle@t-systems.com schreef:
Hi,
If you can run MS-Windows without virtual machine, please visit testbot https://testbot.winehq.org/JobDetails.pl?Key=17175 download the 32 or 64bit executable and execute it.
I can't really trust vm machines for timing, but so far it appears that:
- Vista/w2k8SE/w7 perform rate correction so as to maintain an average number of callbacks
sync.c:583: TimerQueue period 10ms with 0 stress, flags 0 sync.c:558: thread 1340 hpctime 30 delta 15 sync.c:558: thread 1340 hpctime 46 delta 16 sync.c:558: thread 1340 hpctime 46 delta 0 sync.c:601: 80 callbacks within 796/800ms, avg 9.950/10
They'll refire with up to 0 wait upon noticing that it's very late!
sync.c:583: TimerQueue period 10ms with 7 stress, flags 10 sync.c:558: thread 1340 hpctime 46 delta 15 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 53 delta 7 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 62 delta 9 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 77 delta 15 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 84 delta 7 sync.c:570: thread 1340 busy 7ms sync.c:601: 59 callbacks within 607/600ms, avg 10.288/10
It maintains its average even the callback is busy for 7ms within each 10ms interval.
sync.c:583: TimerQueue period 10ms with 12 stress, flags 20 sync.c:558: thread 828 hpctime 31 delta 12 sync.c:570: thread 828 busy 12ms sync.c:558: thread 828 hpctime 43 delta 12 sync.c:570: thread 828 busy 12ms sync.c:601: 42 callbacks within 507/400ms, avg 12.071/10
This one surprises me. No multiple threads are used. Wine uses several threads here. When every callback is busy for 12ms, MS does not reach an average 10ms per invocation, whereas Wine does, thanks to several threads that execute the callbacks concurrently.
I want to figure out why several threads were not used.
sync.c:601: 40 callbacks within 4624/4680ms, avg 115.600/117 Ok. Note that the average is usually slightly lower than expected, simply because the first callback is asked to fire at time period/2.
- w2k/xp do not maintain an average (at least on testbot)
sync.c:583: TimerQueue period 10ms with 0 stress, flags 0 sync.c:558: thread 836 hpctime 30 delta 15 sync.c:558: thread 836 hpctime 46 delta 16 sync.c:601: 51 callbacks within 796/800ms, avg 15.608/10
So at least in testbot, the minimum rate is the well-known 15.625ms interval. Note that the 15.625ms is visible in the w7 testbot results too.
sync.c:583: TimerQueue period 117ms with 0 stress, flags 20 sync.c:558: thread 840 hpctime 311 delta 125 sync.c:558: thread 840 hpctime 436 delta 125 sync.c:601: 37 callbacks within 4561/4680ms, avg 123.270/117
Unlike w7, it never corrects to a smaller interval like 109ms to reach the requested average of 117ms.
This is good news for audio in Wine, because we can make CreateTimerQueue mimic Vista/w2k8/w7 behaviour to give us a stable rate (on average).
The logs are quite long, you can send me them per e-mail.
Thank you, Jörg Höhle
Have you tried changing the resolution with timeBeginPeriod? Supposedly affects those too..
~Maarten
Jörg, do you need more tests? I have a W7 home premium 32bit laptop I can boot.
J. Leclanche
On Tue, Mar 6, 2012 at 4:37 PM, Maarten Lankhorst m.b.lankhorst@gmail.comwrote:
Hey Joerg,
Op 06-03-12 11:21, Joerg-Cyril.Hoehle@t-systems.com schreef:
Hi,
If you can run MS-Windows without virtual machine, please visit testbot https://testbot.winehq.org/JobDetails.pl?Key=17175 download the 32 or 64bit executable and execute it.
I can't really trust vm machines for timing, but so far it appears that:
- Vista/w2k8SE/w7 perform rate correction so as to maintain an average
number of callbacks
sync.c:583: TimerQueue period 10ms with 0 stress, flags 0 sync.c:558: thread 1340 hpctime 30 delta 15 sync.c:558: thread 1340 hpctime 46 delta 16 sync.c:558: thread 1340 hpctime 46 delta 0 sync.c:601: 80 callbacks within 796/800ms, avg 9.950/10
They'll refire with up to 0 wait upon noticing that it's very late!
sync.c:583: TimerQueue period 10ms with 7 stress, flags 10 sync.c:558: thread 1340 hpctime 46 delta 15 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 53 delta 7 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 62 delta 9 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 77 delta 15 sync.c:570: thread 1340 busy 7ms sync.c:558: thread 1340 hpctime 84 delta 7 sync.c:570: thread 1340 busy 7ms sync.c:601: 59 callbacks within 607/600ms, avg 10.288/10
It maintains its average even the callback is busy for 7ms within each
10ms interval.
sync.c:583: TimerQueue period 10ms with 12 stress, flags 20 sync.c:558: thread 828 hpctime 31 delta 12 sync.c:570: thread 828 busy 12ms sync.c:558: thread 828 hpctime 43 delta 12 sync.c:570: thread 828 busy 12ms sync.c:601: 42 callbacks within 507/400ms, avg 12.071/10
This one surprises me. No multiple threads are used. Wine uses several threads here. When every callback is busy for 12ms, MS does not reach an average 10ms per invocation, whereas Wine does, thanks to several threads that execute the callbacks concurrently.
I want to figure out why several threads were not used.
sync.c:601: 40 callbacks within 4624/4680ms, avg 115.600/117 Ok. Note that the average is usually slightly lower than expected, simply because the first callback is asked to fire at time period/2.
- w2k/xp do not maintain an average (at least on testbot)
sync.c:583: TimerQueue period 10ms with 0 stress, flags 0 sync.c:558: thread 836 hpctime 30 delta 15 sync.c:558: thread 836 hpctime 46 delta 16 sync.c:601: 51 callbacks within 796/800ms, avg 15.608/10
So at least in testbot, the minimum rate is the well-known 15.625ms
interval.
Note that the 15.625ms is visible in the w7 testbot results too.
sync.c:583: TimerQueue period 117ms with 0 stress, flags 20 sync.c:558: thread 840 hpctime 311 delta 125 sync.c:558: thread 840 hpctime 436 delta 125 sync.c:601: 37 callbacks within 4561/4680ms, avg 123.270/117
Unlike w7, it never corrects to a smaller interval like 109ms to reach the requested average of 117ms.
This is good news for audio in Wine, because we can make CreateTimerQueue mimic Vista/w2k8/w7 behaviour to give us a stable rate
(on average).
The logs are quite long, you can send me them per e-mail.
Thank you, Jörg Höhle
Have you tried changing the resolution with timeBeginPeriod? Supposedly affects those too..
~Maarten
-
Jerome Leclanche -
Joerg-Cyril.Hoehle＠t-systems.com -
Maarten Lankhorst -
Vitaliy Margolen