Added wine-devel to cc
Op 26-10-12 13:12, Joerg-Cyril.Hoehle(a)t-systems.com schreef:
> Maarten,
>
> I'll try and come up with a review of your winepulse patches yet I'm not familiar with the PA API.
>
> Regarding your dsound ones, I'm sorry I've not enough experience
> with the DSound API to be really useful. I was happy that Alexey Loukianov and A.Eikum
> worked on DSound.
>
> One issue that struck me is the 5ms period downgrade in winepulse.
> I advise you keep that as a separate patch. Halving the externally visible SetEVentHandle rate
> is certainly not something that should be in the one big core patch introducing winepulse.
Yeah this was explicitly to make skyrim work better, I return the updated latency in
GetStreamLatency, and with the fixes wine dsound uses that value for calculating mixing
fraglen.
> Even if it causes no test failure, that trick would certainly be visible in the log lines. Native shows:
> render.c:2084: Should play 1000ms continuous tone with fragment size 480.
> render.c:2136: Released 48000=100x480 -960 frames at 48000 worth 980ms in 1008ms
Yeah I seem to fire more events, so less data gets played.
This requires some rethinking though, winepulse doesn't
attempt to hide latency at all, and so far the mmdevapi tests have failed on my usb
headphones because it didn't always have a smooth buffer increment.
The tests don't fail, but because of the extra firing processing sometimes gets skipped..
Woops, some more digging revealed I also seemed to have done a SetEvent in
pulse_started_callback, which is entirely bogus, presumably a leftover from
before I hooked up the latency callback for when in underrun mode.
With that SetEvent part of the latency hack disabled and the bogus SetEvent removed,
I get:
render.c:2127: Released 44541=101x441 -441 frames at 44100 worth 1000ms in 1003ms
Can't get better than that. :-)
I disabled the exclusive mode on winepulse because I felt that mode was sufficiently
different in behavior, and I don't think the mmdevapi tests cover it properly.
I'll do some more digging if the SetEvent is still needed for the hack, or if
the period lowering is enough. I would suspect lowering the period is sufficient
now. Quick testing of skyrim seems to indicate I can leave the SetEvent part out,
so I pass all tests properly again. :-)
> BTW, I'd still be pleased if you could upload somewhere to bugzilla results from
> runtest -v -i mmdevapi/render and capture
> from your winepulse driver. I think I asked you that favour already but found nothing.
My tree removes todo_wine from the tests, but anyway:
capture.c:501: Returned periods: 10.0000 ms 0.4988 ms
capture.c:513: pwfx: 0xdccb0
capture.c:514: Tag: fffe
capture.c:515: bits: 32
capture.c:516: chan: 2
capture.c:517: rate: 44100
capture.c:518: align: 8
capture.c:519: extra: 22
capture.c:524: Res: 32
capture.c:525: Mask: 3
capture.c:526: Alg: FLOAT
capture.c:585: Returned latency: 10.0000 ms
capture.c:185: Wait'ed position 0 pad 0 flags 0, amount of frames locked: 441
capture.c:247: Sleep.1 position 441 pad 15435 flags 0, amount of frames locked: 441
capture.c:291: GetBufferSize 22050 period size 441
capture.c:301: Overrun position 1323 pad 22050 flags 1, amount of frames locked: 441
capture.c:328: Cont'ed position 1764 pad 21609 flags 0, amount of frames locked: 441
capture.c:352: Restart position 2205 pad 21168 flags 0, amount of frames locked: 441
capture.c:383: Reset position -1 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:409: Running position 23373 pad 7938 flags 0, amount of frames locked: 441
capture: 255 tests executed (0 marked as todo, 0 failures), 0 skipped.
render.c:185: Returned periods: 10.0000 ms 2.0000 ms
render.c:197: pwfx: 0xdccb0
render.c:198: Tag: fffe
render.c:199: bits: 32
render.c:200: chan: 6
render.c:201: rate: 48000
render.c:202: align: 24
render.c:203: extra: 22
render.c:208: Res: 32
render.c:209: Mask: 3f
render.c:210: Alg: FLOAT
render.c:268: Initialize(duration=0) GetBufferSize is 192
render.c:333: Returned latency: 10.0000 ms
render.c:411: IsSupported(shared , 8000x 8x1)
render.c:411: IsSupported(shared , 8000x 8x2)
render.c:411: IsSupported(shared , 8000x16x1)
render.c:411: IsSupported(shared , 8000x16x2)
render.c:411: IsSupported(shared , 11025x 8x1)
render.c:411: IsSupported(shared , 11025x 8x2)
render.c:411: IsSupported(shared , 11025x16x1)
render.c:411: IsSupported(shared , 11025x16x2)
render.c:411: IsSupported(shared , 12000x 8x1)
render.c:411: IsSupported(shared , 12000x 8x2)
render.c:411: IsSupported(shared , 12000x16x1)
render.c:411: IsSupported(shared , 12000x16x2)
render.c:411: IsSupported(shared , 16000x 8x1)
render.c:411: IsSupported(shared , 16000x 8x2)
render.c:411: IsSupported(shared , 16000x16x1)
render.c:411: IsSupported(shared , 16000x16x2)
render.c:411: IsSupported(shared , 22050x 8x1)
render.c:411: IsSupported(shared , 22050x 8x2)
render.c:411: IsSupported(shared , 22050x16x1)
render.c:411: IsSupported(shared , 22050x16x2)
render.c:411: IsSupported(shared , 44100x 8x1)
render.c:411: IsSupported(shared , 44100x 8x2)
render.c:411: IsSupported(shared , 44100x16x1)
render.c:411: IsSupported(shared , 44100x16x2)
render.c:411: IsSupported(shared , 48000x 8x1)
render.c:411: IsSupported(shared , 48000x 8x2)
render.c:411: IsSupported(shared , 48000x16x1)
render.c:411: IsSupported(shared , 48000x16x2)
render.c:411: IsSupported(shared , 96000x 8x1)
render.c:411: IsSupported(shared , 96000x 8x2)
render.c:411: IsSupported(shared , 96000x16x1)
render.c:411: IsSupported(shared , 96000x16x2)
render.c:2174: Output to a MS-DOS console is particularly slow and disturbs timing.
render.c:2175: Please redirect output to a file.
render.c:870: Testing shared mode
render.c:902: Latency: 10.0000 ms
render.c:921: BufferSize 24000 estimated fragment 480 x 50 = 24000
render.c:945: Clock Frequency 1152000
render.c:974: data at 0x530030
render.c:1023: padding 14302 past sleep #2
render.c:1042: padding 14302 position 232752 past stop #2
render.c:1076: data at 0x530030
render.c:1100: position 115416 past 100ms sleep #3
render.c:1117: padding 18711 position 126936 past stop #3
render.c:1145: data at 0x530030 for prefill 22500
render.c:1175: hpctime 381 after 370ms
render.c:1194: hpctime 481 pcpos 492
render.c:1199: padding 1250 position 510000/21250 slept 470ms iteration 0
render.c:1227: data at 0x530030
render.c:1194: hpctime 589 pcpos 599
render.c:1199: padding 18551 position 634776/26449 slept 570ms iteration 1
render.c:1232: data at 0x530030 (small 5449)
render.c:1194: hpctime 691 pcpos 701
render.c:1199: padding 19321 position 747072/31128 slept 670ms iteration 2
render.c:1232: data at 0x530030 (small 4679)
render.c:1194: hpctime 793 pcpos 803
render.c:1199: padding 18727 position 873624/36401 slept 770ms iteration 3
render.c:1232: data at 0x530030 (small 5273)
render.c:1194: hpctime 895 pcpos 905
render.c:1199: padding 19089 position 991488/41312 slept 870ms iteration 4
render.c:1232: data at 0x530030 (small 4911)
render.c:1194: hpctime 996 pcpos 1007
render.c:1199: padding 19279 position 1104792/46033 slept 970ms iteration 5
render.c:1232: data at 0x530030 (small 4721)
render.c:1194: hpctime 1098 pcpos 1109
render.c:1199: padding 18961 position 1225728/51072 slept 1070ms iteration 6
render.c:1232: data at 0x530030 (small 5039)
render.c:1194: hpctime 1200 pcpos 1211
render.c:1199: padding 19326 position 1337904/55746 slept 1170ms iteration 7
render.c:1232: data at 0x530030 (small 4674)
render.c:1194: hpctime 1302 pcpos 1312
render.c:1199: padding 18970 position 1458624/60776 slept 1270ms iteration 8
render.c:1232: data at 0x530030 (small 5030)
render.c:1248: position 1458624
render.c:1257: position 2034624 past underrun, 0 padding left, 84776 frames written
render.c:1279: hpctime 2304 after underrun
render.c:882: Testing exclusive mode at 48000
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -480 frames at 48000 worth 1000ms in 1002ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -480 frames at 48000 worth 1000ms in 1004ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -960 frames at 48000 worth 990ms in 1003ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -480 frames at 48000 worth 1000ms in 1007ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -480 frames at 48000 worth 1000ms in 1002ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -480 frames at 48000 worth 1000ms in 1005ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -960 frames at 48000 worth 990ms in 997ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -960 frames at 48000 worth 990ms in 999ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -330 frames at 48000 worth 1003ms in 1009ms
render.c:2075: Should play 1000ms continuous tone with fragment size 480.
render.c:2127: Released 48480=101x480 -960 frames at 48000 worth 990ms in 1003ms
render: 4996 tests executed (0 marked as todo, 0 failures), 0 skipped.
Sometimes up to 2 tests fail due to position updates not being regular, as you can
see from this line:
render.c:2127: Released 48480=101x480 -330 frames at 48000 worth 1003ms in 1009ms
I suspect this is because it's nearly done playing though, but it can get worse
when you use usb headphones, not much I can do about that though, except if I
started lying, but it's so far been much simpler when I don't..
Exclusive mode tests aren't done, I disabled exclusive mode because I felt tests
were insufficient. If you can point me to an application using it I'll work on it
though, but I didn't feel mmdevapi tests were complete enough for handling this.
*BONUS*
My favorite capture results (a2dp phone as "microphone"):
capture.c:501: Returned periods: 135.2834 ms 135.2834 ms
capture.c:513: pwfx: 0xdccb0
capture.c:514: Tag: fffe
capture.c:515: bits: 32
capture.c:516: chan: 2
capture.c:517: rate: 44100
capture.c:518: align: 8
capture.c:519: extra: 22
capture.c:524: Res: 32
capture.c:525: Mask: 3
capture.c:526: Alg: FLOAT
capture.c:585: Returned latency: 135.2834 ms
capture.c:168: Test failed: Waiting on event handle failed!
capture.c:185: Wait'ed position -1 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:217: Test failed: GetNextPacketSize 0 vs. GCP 0
capture.c:220: Test failed: Valid IAudioCaptureClient_GetBuffer returns 08890001
capture.c:247: Sleep.1 position -1 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:286: Test failed: GetNextPacketSize 0 vs. GetDevicePeriod 5966
capture.c:291: GetBufferSize 23864 period size 5966
capture.c:299: Test failed: Valid IAudioCaptureClient_GetBuffer returns 08890001
capture.c:301: Overrun position -1 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:326: Test failed: Valid IAudioCaptureClient_GetBuffer returns 08890001
capture.c:328: Cont'ed position -1 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:347: Test failed: Valid IAudioCaptureClient_GetBuffer returns 08890001
capture.c:352: Restart position -559038737 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:354: Test failed: restarted GCP 0
capture.c:383: Reset position -1 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:408: Test failed: Valid IAudioCaptureClient_GetBuffer returns 08890001
capture.c:409: Running position -1 pad 0 flags abadcafe, amount of frames locked: 0
capture.c:426: Test failed: Wait(event) after Stop gave 102
capture.c:434: Test failed: Wait(event) after Reset gave 102
capture.c:440: Test failed: Wait(NULL event) gave 102
capture: 224 tests executed (0 marked as todo, 12 failures), 0 skipped.
I love this one because it shows that when you have a source that's not
capturing, winepulse still gets the correct results. Even though obviously the
tests completely fail because there's no data. ;-)
~Maarten
