Added wine-devel to cc
Op 26-10-12 13:12, Joerg-Cyril.Hoehle@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