auich.settings not installed

[Pete]

Ever since I installed Haiku on my machine with the auich soundset, I was having problems with audio not working. (MediaPlayer would play, but no sound would come out, then later on it would suddenly work.)

I noticed, running 'tail -F var/log/syslog', that whenever I had silence I saw "Buffer late" messages.

Digging into the source, I noticed that there is an 'auich.settings' file in the driver directory, that says it should be installed in /boot/home/config/settings. I did so, and uncommented the buffer settings within it, and ever since the MediaPlayer has played music perfectly.

It seems either this file (with buffer settings enabled) should be installed, or there should be explicit instructions somewhere that this will probably be necessary.

[ttcoder]

Same problem, and same solution (great find!) here: I've created a config file as pointed out by Pete and now sound works from the beginning. At first I just enabled the first line but it seemed to cause instability in VESA mode, so now I'm running with the first 3 lines enabled and things seem to be peachy:

# Settings file for the auich driver
#
# This file should be moved to the directory
# ~/config/settings/kernel/drivers/

sample_rate    48000
buffer_frames  256
buffer_count   4
#use_thread false

I understand the devs cannot be everywhere all the time so if nobody comments on this ticket I'll start digging into the source a little, see if I can pinpoint the problem some more (i.e. why is audio postponed by several minutes after bootup when the file is not present, and why is the file not present on a default RAW image of haiku anyway).. I'm a C++ guy, not a Media Kit guy however...

[korli]

For the record, the lines you uncomment were the default until hrev33347. See ticket #4656

[axeld]

I think it's a good idea to try to make this the default again, and see it #4656 pops up again.

[ttcoder]

And I'll try (fairly soon) to tweak the settings as per korli's info, reboot, and see what changes.

Looks like I'll have to open this tower and unplug the SB-Live I'm using since last week though, as the Auich on-board is not listed any more in Media Prefs since I've put the SB-Live in a PCI slot (not sure if this is normal behavior but I'm tempted to file a ticket for that too?).

[Pete]

Replying to axeld:

I think it's a good idea to try to make this the default again, and see it #4656 pops up again.

I suspect it will... (:-/) #4656 sounds very much like what I've been fighting in #7285! The latency increases cause audible crackles each time they occur, and eventually exceed the buffers provided, so the sound gets garbled. There never was any indication that it might be the audio driver itself that was the problem, though. It's things like moving windows around that cause the glitches.

I've just revisited this -- setting buffer size in auich.settings to 4096 -- and, as before, I immediately lose all sound. My test app (modified ToneProducer) still shows latency glitches, even though I don't hear them.

For interest, I increased the buffer count instead (by a lot -- to 64 -- to keep the total frames the same with a 256 frame buffer). I get sound, but with continuous 'ticking' (at about 6/sec) superimposed. By my quick calculation, that's about twice the rate that the buffer chain circulates (256*64/48000.0) so I have no idea what the reason might be.

I used to get sound eventually with the old large buffer size, so I've left the machine running in that state, to see if I can notice anything if and when sound appears.

[Pete]

Okay, I left Haiku running a while, and as hoped the sound came back.

And I can verify that the crackles disappear with the larger buffer.

However... the latency still increases every time a window gets moved, and once again it eventually reaches a point where the buffer pool can no longer handle it, and the sound breaks up.

Also, the real-time delay in this condition is always about 1/5 sec, which is quite impossible for driving the soft synth from my digital piano!

[ttcoder]

Here goes for me:
I've seen speed listed as a consideration in the other ticket, so for the record this is an Athlon XP 1800+ box.

Listdev:

device Multimedia controller (Multimedia audio controller) [4|1|0]
  vendor 1039: Silicon Integrated Systems [SiS]
  device 7012: AC'97 Sound Controller

Syslog:

KERN: auich: auich_setup(0x817a6500)
KERN: auich: audio/hmulti/auich/1 deviceid = 0x7012 chiprev = a0 model = 7012 enhanced at dc00
(..)
KERN: auich: installing interrupt : 12
KERN: auich: init_driver done
KERN: auich: publish_devices()
KERN: auich: publish audio/hmulti/auich/1
KERN: auich: find_device(audio/hmulti/auich/1)

Tests:
Created the file with just one overriden setting, changing it and rebooting to see if audio is available immediately, and "shaking" a blank WebPositive window in front of another one loading a page to see if sound becomes choppy:

~> cat /boot/home/config/settings/kernel/drivers/auich.settings 
buffer_frames  256
~>

Results:

• no override: no sound at bootup (and oddly it still did not arrive even 15+ minutes later, and launching an mp3 in MediaPlayer results just in its progress bar "jumping" to close to the end)
• "buffer_frames  128" -> audio ok immediately; gets chopped off a fair bit if I "shake" around a W+ window.
• "buffer_frames  256" -> audio ok immediately; gets chopped off a bit on W+ test
• Edit:
• "buffer_frames  512" -> audio ok immediately; gets chopped off a bit on W+ test
• "buffer_frames  1024" -> No Audio after media restart. After ca. 7 minutes it comes back; though MediaPlayer must be out of the way -- not running -- at the seven minutes mark it seems.. Once the mark is passed, starting it once results in some relatively garbled sound; restarting it again and the sound is perfect (and no more messages in syslog to the tune of "KERN: Received buffer 3455 usec late").

[So to summarize, buffersizes in the 128-to-512 range allow audio to work immediately here, and audio glitches are hard to eradicate -- but for the latter I'm starting to suspect it's something to do with network activity, since glitches seem to stop when the W+ page if done loading..]

I'll stay with Auich a couple more days before plugging the SB-live back in.

[Pete]

Replying to ttcoder:

Here goes for me:

Thanks for doing the check.

Results:

• no override: no sound at bootup (and oddly it still did not arrive even 15+ minutes later, and launching an mp3 in MediaPlayer results just in its progress bar "jumping" to close to the end)
• "buffer_frames 128" -> audio ok immediately; gets chopped off a fair bit if I "shake" around a W+ window.
• "buffer_frames 256" -> audio ok immediately; gets chopped off a bit on W+ test
• [I will continue increasing buffer size later on as time permits and edit this comment accordingly]

Seems to mirror my observations pretty closely. (Though I've never noticed that progress bar jump -- it seems to move normally, even though no sound comes out.)

This all leads to a couple of relevant questions:

• Why was the "no sound" effect not noticed when the change was first made? Has something changed further back in the chain -- multiaudio perhaps? FWIW I have the same situation on an old Thinkpad that needs OSS for audio; OSS also has a very large buffer by default, and a giant latency. I haven't had a chance to play with modifying OSS yet.

• It appears as if these problems don't happen with other audio drivers. I assume they'd have been reported if they did. The latency glitches (#7285) seem to happen anywhere in the chain -- they aren't obviously associated with the driver. And, as noted, they seem to be generated largely by window movements. So how are these affecting the driver? (Looks as if interrupts are getting turned off for ~8msec.)

I'll stay with Auich a couple more days before plugging the SB-live back in.

When you do, could you please report what Cortex shows as the latency for, say, MediaPlayer? I get ~170 msec with the default 4096 buffer size. (With 256-frame buffers, it becomes 17-20 msec... until the latency glitches hit!)

For reference, my box is a Pentium 4 @ 2.79GHz. listdev shows:

device Multimedia controller (Multimedia audio controller) [4|1|0]
  vendor 8086: Intel Corporation
  device 24d5: 82801EB/ER (ICH5/ICH5R) AC'97 Audio Controller

[ttcoder]

Replying to Pete:

Seems to mirror my observations pretty closely. (Though I've never noticed that progress bar jump -- it seems to move normally, even though no sound comes out.)

Same here now that I experimented with bufferframes of no more than 1024.. Odd that this behavior changes too.. And only on this setup but not yours.. Whatever the root cause of the bug is, it is kinda rich in consequences.

I'll stay with Auich a couple more days before plugging the SB-live back in.

When you do, could you please report what Cortex shows as the latency for, say, MediaPlayer? I get ~170 msec with the default 4096 buffer size. (With 256-frame buffers, it becomes 17-20 msec... until the latency glitches hit!)

Clicking "Get Info.." for "Mediaplayer audio out" I see 17.91 ms when buffer is at 1024, and Latency:14.88 ms for buffer_frames =512 I'll report on the values with SB-Live/emuxki.

(BTW, rebooting isn't needed when you change the settings file... A lot quicker just to Restart Audio Services in the preferences panel.)

D'oh! Seems I took bad habits due to #4285. Testing is much less painful now thx to your reminder, that's for sure..!

---

Miscellanious notes..

Looked at the whole audio drivers source tree and found ​kernel/media/audio/ich which just contains some print("hello world") statements.. Looking further, it seems to be tied to ​kernel/drivers/audio/module_driver or something. Not sure what that is about.

Back to auich, noticed it is possible to activate a verbose log with the right compile-time defs:

​auich/debug.c#L40 (static const char * logfile="/boot/home/auich.log" ..etc)

And of course, noticed the big-bad-ass ac97.c file (up one directory level) is also part of the driver in fact, so in all this is quite a sizeable beast to read and review :-] .. !

If I have a chance in the future I plan to 1) setup for building the driver from source here; 2) activate the logfile and 3) if the logfile yields no hint, grep the sources for "current_settings.buffer_frames" and try to understand how this variable can have a 'threshold' that triggers the delayed-audio bug between 512 and 1024. Maybe when crossing that threshold and allocating the bigger buffers it steps over some memory bounds or something. Could even try to set it to some dementedly high value to see if it triggers a crash :-)...

This will be (almost) my first foray into kernelland and drivers however, so I don't expect too much.

[stargatefan]

following Petes instruction here resolved my audio problems with ich4 as noted in 7442

[Pete]

Replying to ttcoder:

Replying to Pete:

I get ~170 msec with the default 4096 buffer size. (With 256-frame buffers, it becomes 17-20 msec... until the latency glitches hit!)

Clicking "Get Info.." for "Mediaplayer audio out" I see 17.91 ms when buffer is at 1024, and Latency:14.88 ms for buffer_frames =512

Sounds about what I'd expect.

I'll report on the values with SB-Live/emuxki.

I'm going to be rather interested to see that!

Looked at the whole audio drivers source tree [...]

If I have a chance in the future I plan to 1) setup for building the driver from source here;

I'd be inclined not to worry about the driver too much. I don't think the root problem is there [see my next post], and actually a large buffer size is not really a fix because it inherently also means a long latency, which makes the whole thing useless for anything real time. [We do not want to be worse than Windows! (:-)]

[Pete]

A significant finding (I think):

I finally realized it wasn't completely useless to just remove the auich driver and see what happens. The audio chain runs just fine when I do -- presumably with the null-audio driver (though I see nothing in syslog about it).

When I do this, and, say, play an mp3, I still see the latency reported by Cortex increasing when I wiggle windows, and my test app I've been using to look at the 'blackouts' behind all this still shows the same rate of blackouts in the same sort of places. (The latency without an actual driver is initially less than 1 msec, but increases rapidly when glitches occur.)

Which means that the crackles are nothing to do with the audio hardware. If they really don't occur with other audio drivers (and are not just being masked by perhaps a large default buffer size) something very odd is going on!

[ttcoder]

Replying to Pete:

I'll report on the values with SB-Live/emuxki.

I'm going to be rather interested to see that!

Latency is significantly higher with the SB-Live: Cortex's Get Info on "MediaPlayer audio out" claims a Latency of 26.36 ms. (maybe the bigger buffers/latency is the reason why the SB-Live has few glitches, or am I completely off on this) -- udpate: I've noticed it changes slightly depending on file type: if playing an mp3 instead of WAV, latency goes down to 24.72 ms. Update2: one minute into the mp3 it now says 34.48 ms, is that normal ? Update 3: now up to 76.89 ms, and stays so until the end of the mp3 ?? Weird. Ok I'll let more media-savvy folks try to reproduce that one. Note: I have a dozen "buffer late" notices in syslog:

KERN: Received buffer 1759 usec late
KERN: sending notify
KERN: Received buffer 5259 usec late ...
KERN: Received buffer 24173 usec late ..
KERN: Received buffer 2822 usec late
KERN: Received buffer 20417 usec late
KERN: Received buffer 4174 usec late
KERN: Received buffer 9756 usec late
KERN: Received buffer 42408 usec late...
KERN: Received buffer 6867 usec late
KERN: sending notify

Anyway I think I'll wait until #7882 (another good find, that one, didn't know there was a problem with media-kit thread priorities!) is addressed before coming back to this ticket.. Just in case that one improves this one.. EditToAdd: my hunch that 7882 is relevant to us, is that both me and seemingly Pete have single-CPU machines, and presumably the devs have multi-CPU machines, so we see bugs that they don't see, as hinted at in the 7882 ticket.

Also call me Captain Obvious but I've just realized that in the above part of this comment I'm just repeating what Pete already noticed, just with more numbers :-P .. So looks like Pete's on to something here.

[Pete]

Replying to ttcoder:

Replying to Pete:

I'll report on the values with SB-Live/emuxki.

Latency is significantly higher with the SB-Live: Cortex's Get Info on "MediaPlayer audio out" claims a Latency of 26.36 ms.

Thanks for that. Very useful added information.

Actually that's not too bad a latency (better than I get on BeOS, anyway). And compared to what HDA seems to work at currently (up to 300 msec delay, apparently) it's excellent!

Update2: one minute into the mp3 it now says 34.48 ms, is that normal ? Update 3: now up to 76.89 ms, and stays so until the end of the mp3 ?? Weird. Ok I'll let more media-savvy folks try to reproduce that one. Note: I have a dozen "buffer late" notices in syslog [....]

Yep -- just about exactly what I'm seeing. Caused by the mysterious 'blackouts' (#7285). My revised media code I posted in that ticket improves the media kit response to the blackouts, but doesn't help individual apps' behaviour; if they -- as normal -- use the B_INCREASE_LATENCY mode, they'll be affected by the blackouts in the same way. I think the 76.89 ms is a maximum set by the program to prevent total meltdown.

Anyway I think I'll wait until #7882 (another good find, that one, didn't know there was a problem with media-kit thread priorities!) is addressed before coming back to this ticket.. Just in case that one improves this one..

I find I get the glitches (blackouts) with just about any display action, not just WP, so I don't know...

[anevilyak]

(In #8009) Dell's official spec for the c640 indicates it's using an ICH3 chipset (Cirrus Logic SC4205).

Duplicate of #7284 indeed.

[anevilyak]

(In #8086) Duplicate of #7284.

[pulkomandy]

Most of the crackling audio and increasing latency problems are actually because of our scheduler still has no priority inversion system.

It should work as follows :

• The media threads in the system have a fairly high priority.
• The application threads, on the other hand, have a lower priority
• When there is some CPU load (moving windows around is a good way to do that, as we have no 2d acceleration), there is not enough time to do everything. The window stuff is running at display priority, so it is between the app and the media kit.
• As the app has lower priority, it doesn't get enough time to fill the buffers, and they become empty
• The media kit notices it and increases the latency to avoid it hapenning again.

How to fix it : The scheduler should handle priority inversion on ports (the kernel level system used for media kit streams). That is, when the media kit needs some data from the app, and there's nothing in the buffer, the app should get its priority temporarily increased to the same as the media kit, untill the buffer is filled again. This way, the buffer will not get empty that often, the media kit will not notice problems and will stop increasing latency.

The problem is not on the hardware/driver side, it's a similar lockout between threads but is pure software, no interrupts are involved.

You can find some patches that add priority inversion to the kernel in the development mailing list (maybe as a trac ticket as well?). Please test these.

[Pete]

Replying to pulkomandy:

Most of the crackling audio and increasing latency problems are actually because of our scheduler still has no priority inversion system.

Yep... (:-))

You can find some patches that add priority inversion to the kernel in the development mailing list (maybe as a trac ticket as well?). Please test these.

The ticket with the patch to date is #8007. I have tested it, and unfortunately it's not usable yet. (Priority is appropriately raised, but never goes down again, so you're left with an app running at pri 120!) Julian says he will fix, but hasn't gotten back to it yet. I'd like to take a look at it myself, and will if I get time, but it's pretty much starting from scratch for me.

[Giova84]

Haiku hrev46301

This bug seems gone, at least for me. (i experienced this bug two years ago: https://dev.haiku-os.org/ticket/8086 )

[pulkomandy]

Things have gotten better with #8007 fixed and the new scheduler I guess. Should we make the buffer size in auich smaller by default again?

[ttcoder]

(note to self: #7546)

[mmlr]

This (and the most recently referenced #7546) sound like they were caused by the uninitialized values for drift calculation in the multi audio addon which would be fixed by hrev54464. Changing the buffer exchange rate would affect it in so far as that the uninitialized entry would be overwritten (and therefore initialized) more or less quickly. That would in turn make the window of time where the bug could be triggered smaller or larger. Is there still a chance to get this verified or is the hardware all gone?