Reply
Thread Tools
Posts: 9 | Thanked: 9 times | Joined on Nov 2008
#41
Originally Posted by MrWeasel View Post
I did just what you said, the logs are attached. I noticed some dbus error. That one occured during the period where hfconsole was not responding. I waited until it came back and then closed it and afterwards hfpd. From the trace it seems as hfpd was still busy at that point :/
Hi MrWeasel,

Thanks again for trying that out. It looks like the latency instrumentation was added to just the right place.

Code:
HFPD: ** OpLatency: ALSA SndPushInput took 3508ms
HFPD: ** OpLatency: ALSA SndPushInput took 7139ms
HFPD: ** OpLatency: ALSA SndPushInput took 14954ms
HFPD: ** OpLatency: ALSA SndPushInput took 29063ms
The alsa-dsp plugin appears to use the pcm_ioplug interface for creating alsa-lib plugins, which seems like a good way to do it. pcm_ioplug provides a nonblocking flag that plugins are supposed to use in order to provide the right interface. Unfortunately alsa-dsp appears to ignore nonblocking and its transfer call blocks unconditionally. This causes hfpd to get stuck as above.

So, unless somebody knows how to add nonblocking support to alsa-dsp, it looks like the next direction to take this project is to create a gstreamer backend module. That's going to be messy.
 
qole's Avatar
Moderator | Posts: 7,109 | Thanked: 8,820 times | Joined on Oct 2007 @ Vancouver, BC, Canada
#42
samr7: we posted almost simultaneously, so you might have missed my post. Please see if my previous post is of any use to you...

Having read your post, it would seem that it is not going to be useful, since you seem to have found the problem with your app.
__________________
qole.org --- twitter --- Easy Debian wiki page
Please don't send me a private message, post to the appropriate thread.
Thank you all for your donations!
 

The Following User Says Thank You to qole For This Useful Post:
Posts: 9 | Thanked: 9 times | Joined on Nov 2008
#43
Originally Posted by qole View Post
Here's an interesting post about using Gnome Alsa Mixer to play mic input through BT headphones... for 5 seconds before something mysterious and internal kills the audio. Could this have anything to do with current difficulties?
Hi qole,

This is some interesting information!

I doubt the issue with multimediad is related to the alsa-lib problem that seems to be wreaking havoc with hfpd.

OTOH, it sounds like there is significant overlap of functionality between multimediad and hfpd, at least as far as transferring data between a Bluetooth audio device and the local sound card. As long as multimediad doesn't die after five seconds it might prove an easy way to get hands-free working. I can add a configuration option to have hfpd disable its SCO audio support and depend on multimediad if you think that could possibly work.

hfpd attempts to implement its own auto-gain and echo cancelation. I don't know how important any of this will be with a tablet, but would you happen to know the feature set of multimediad?

Thanks!
 

The Following User Says Thank You to samr7 For This Useful Post:
qwerty12's Avatar
Posts: 4,274 | Thanked: 5,358 times | Joined on Sep 2007 @ Looking at y'all and sighing
#44
Originally Posted by samr7 View Post
but would you happen to know the feature set of multimediad?
multimediad is closed source. But it does do some interesting things. It does read /usr/share/alsa/alsa.conf (linked to libasound.so.2) when starting up. It monitors gconf settings for the "level" of sound to make when tapping the screen (which makes sense as it is linked to libts-0.0.so.0 & libgconf-2.so.4),
watches gconf to monitor changes to the /apps/osso/sound/master_volume key,
org.bluez.audio.Headset - seems to monitor dbus for this service ("Playing from bluez audio service, switch BT on", /org/bluez/audio, org.bluez.audio.Manager, /com/nokia/bluez_audio_proxy), it monitors when the headset is connected and mutes the speaker,
/dev/dsptask/audiopp, /dev/dsptask/pcm0 - uses those dsp related devices,
it monitors mce to see when the tablet has been locked and does something that I can't seem to find.

P.S Sorry for the horrible layout of this post
 

The Following 3 Users Say Thank You to qwerty12 For This Useful Post:
Posts: 961 | Thanked: 565 times | Joined on Jul 2007 @ Tyneside, North East England
#45
just checked out and compiled HFP svn revision 58 to see if anything has changed. Unforunately not, it still karks over th audio. Here is a log at an incoming call attempt. This is on an N800 with latest flash and SSUs should it make any difference.



HFPD: >> +CIEV: 2,1
HFPD: >> +CIEV: 3,0
HFPD: >> +CIEV: 4,0
HFPD: HCI Command status: 0x00 0x01 0x040f
HFPD: AudioGatewayStart: /net/sf/nohands/hfpd/00_1D_6E_74_AE_F6
HFPD: ** OpLatency: primary open took 17ms
HFPD: ALSA play state: 2
HFPD: ALSA play state: 2
HFPD: ALSA rec state: 2
HFPD: ALSA rec state: 2
HFPD: Pump: packet size = 24
HFPD: Pump: bot packet size = 160
HFPD: Pump: bot input max fill = 752
HFPD: Pump: bot min fill = 752
HFPD: Pump: bot max fill = 1504
HFPD: Pump: top packet size = 24
HFPD: Pump: top input max fill = 752
HFPD: Pump: top min fill = 752
HFPD: Pump: top max fill = 1504
HFPD: Pump: watchdog timeout = 500
HFPD: Echo tail: 800
HFPD: ALSA play state: 2
HFPD: ALSA rec state: 2
HFPD: ** OpLatency: bottom EP start took 11ms
HFPD: ** OpLatency: async process overall took 113ms
HFPD: ** OpLatency: ALSA SndPushOutput took 831ms
HFPD: ** OpLatency: ALSA async overall took 950ms
HFPD: SoundIoPump: bottom input underprocessed (0 < 1000)
HFPD: SoundIoPump: bottom output underprocessed (0 < 1000)
HFPD: SoundIoPump: top input underprocessed (0 < 1000)
HFPD: SoundIoPump: top output underprocessed (0 < 1000)
HFPD: ** OpLatency: async process overall took 45ms
HFPD: ** OpLatency: ALSA SndPushOutput took 60ms
HFPD: ** OpLatency: ALSA async overall took 112ms
HFPD: ** OpLatency: ALSA SndPushInput took 104ms
HFPD: ** OpLatency: async process overall took 112ms
HFPD: ** OpLatency: ALSA SndPushOutput took 57ms
HFPD: ** OpLatency: ALSA async overall took 282ms
HFPD: AudioGatewayStart: /net/sf/nohands/hfpd/00_1D_6E_74_AE_F6
HFPD: ** OpLatency: ALSA SndPushInput took 286ms
HFPD: ** OpLatency: async process overall took 107ms
HFPD: ** OpLatency: ALSA SndPushOutput took 57ms
HFPD: ** OpLatency: ALSA async overall took 459ms
HFPD: ** OpLatency: ALSA SndPushInput took 645ms
HFPD: ** OpLatency: async process overall took 106ms
HFPD: ** OpLatency: ALSA SndPushOutput took 58ms
HFPD: ** OpLatency: ALSA async overall took 817ms
HFPD: SoundIoPump: bottom input overprocessed (9440 > 8000)
HFPD: SoundIoPump: top input underprocessed (0 < 1000)
HFPD: SoundIoPump: top output underprocessed (0 < 1000)
HFPD: ** OpLatency: ALSA SndPushInput took 1362ms
HFPD: ** OpLatency: async process overall took 108ms
HFPD: ** OpLatency: ALSA SndPushOutput took 61ms
HFPD: ** OpLatency: ALSA async overall took 1539ms
HFPD: ** OpLatency: ALSA SndPushInput took 2806ms
HFPD: ** OpLatency: async process overall took 108ms
HFPD: ** OpLatency: ALSA SndPushOutput took 61ms
HFPD: ** OpLatency: ALSA async overall took 2983ms
HFPD: AudioGatewayStart: /net/sf/nohands/hfpd/00_1D_6E_74_AE_F6
HFPD: SoundIoPump: bottom input overprocessed (33920 > 8000)
HFPD: SoundIoPump: Top endpoint timeout
HFPD: SoundIoPump Stopped
HFPD: ** OpLatency: primary close took 49ms
HFPD: Sound card failed: SoundIoPump: Top endpoint timeout
HFPD: HCI Command status: 0x00 0x01 0x0803
HFPD: HCI Command status: 0x00 0x01 0x0406
HFPD: >> +CIEV: 2,0
HFPD: HCI Command status: 0x00 0x01 0x0804
HFPD: HCI Command status: 0x00 0x01 0x0803
HFPD: HCI Command status: 0x00 0x01 0x0409
HFPD: HCI Command status: 0x00 0x01 0x040f
HFPD: AudioGatewayStart: /net/sf/nohands/hfpd/00_1D_6E_74_AE_F6
HFPD: ** OpLatency: primary open took 127ms
HFPD: ALSA play state: 2
HFPD: ALSA play state: 2
HFPD: ALSA rec state: 2
HFPD: ALSA rec state: 2
HFPD: Pump: packet size = 24
HFPD: Pump: bot packet size = 160
HFPD: Pump: bot input max fill = 752
HFPD: Pump: bot min fill = 752
HFPD: Pump: bot max fill = 1504
HFPD: Pump: top packet size = 24
HFPD: Pump: top input max fill = 752
HFPD: Pump: top min fill = 752
HFPD: Pump: top max fill = 1504
HFPD: Pump: watchdog timeout = 500
HFPD: Echo tail: 800
HFPD: ALSA play state: 2
HFPD: ALSA rec state: 2
HFPD: ** OpLatency: async process overall took 88ms
HFPD: ** OpLatency: ALSA SndPushOutput took 830ms
HFPD: ** OpLatency: ALSA async overall took 923ms
HFPD: SoundIoPump: bottom input underprocessed (0 < 1000)
HFPD: SoundIoPump: bottom output underprocessed (0 < 1000)
HFPD: SoundIoPump: top input underprocessed (0 < 1000)
HFPD: SoundIoPump: top output underprocessed (0 < 1000)
HFPD: ** OpLatency: async process overall took 44ms
HFPD: ** OpLatency: ALSA SndPushOutput took 58ms
HFPD: ** OpLatency: ALSA async overall took 108ms
HFPD: ** OpLatency: ALSA SndPushInput took 105ms
HFPD: Write SCO data: Connection reset by peer
HFPD: Write SCO data: Transport endpoint is not connected
HFPD: ** OpLatency: async process overall took 114ms
HFPD: ** OpLatency: ALSA SndPushOutput took 60ms
HFPD: ** OpLatency: ALSA async overall took 287ms
HFPD: Top endpoint caused pump halt: Fatal SCO write error: Transport endpoint is not connected
HFPD: SoundIoPump Stopped
HFPD: ** OpLatency: primary close took 33ms
 
Posts: 9 | Thanked: 9 times | Joined on Nov 2008
#46
I just committed a change to support multithreading in the ALSA backend for HFP for Linux. When the sound card is opened, and threaded access is configured, it will create a thread just for reading samples from the audio device, and another just for writing samples to the audio device. This should not require nonblocking mode to work and might be enough to get audio to work on Maemo with the alsa-dsp plugin.

Anybody up for trying this out?

To configure threaded access:
  1. Get the latest sources from SVN
  2. Open the preferences dialog, select the Audio Device tab
  3. In the device/options field, enter:
    Code:
    access=thread
    See the attachment.

Then try the feedback test. If it still doesn't work on Maemo, gstreamer will have to be next.
Attached Images
 
 

The Following 3 Users Say Thank You to samr7 For This Useful Post:
qwerty12's Avatar
Posts: 4,274 | Thanked: 5,358 times | Joined on Sep 2007 @ Looking at y'all and sighing
#47
Originally Posted by samr7 View Post
I just committed a change to support multithreading in the ALSA backend for HFP for Linux. When the sound card is opened, and threaded access is configured, it will create a thread just for reading samples from the audio device, and another just for writing samples to the audio device. This should not require nonblocking mode to work and might be enough to get audio to work on Maemo with the alsa-dsp plugin.

Anybody up for trying this out?

To configure threaded access:
  1. Get the latest sources from SVN
  2. Open the preferences dialog, select the Audio Device tab
  3. In the device/options field, enter:
    Code:
    access=thread
    See the attachment.

Then try the feedback test. If it still doesn't work on Maemo, gstreamer will have to be next.
The preferences window fails to work for me now:

Traceback (most recent call last):
File "./hfconsole", line 1089, in config_open
savecfg = self.config_get_vals()
File "./hfconsole", line 1185, in config_get_vals
vals['denoise'] = spr['Denoise']
KeyError: 'Denoise
'

So I edited ~/.hfconsole and put access=thread under [options] manually. When I dial, I get audio open for a few seconds (no sound) but then the phone reports "transferred to phone (as opposed to a headset)" and it says "primary sound card failure".

HFPD: HCI Command status: 0x00 0x01 0x0405
HFPD: HCI Command status: 0x00 0x01 0x041b
HFPD: SDP: Supported features: 17
HFPD: HCI Command status: 0x00 0x01 0x0419
HFPD: HCI Name request complete (0): "<removed>" -> " P!MP"
HFPD: << AT+BRSF=15
HFPD: >> +BRSF:55
HFPD: >> OK
HFPD: << AT+CIND=?
HFPD: >> +CIND: ("battchg",(0-5)),("signal",(0-5)),("batterywarning",(0-1)),("chargerconnected",(0-1)),("service",(0-1)),("sounder",(0-1)),("message",(0-1)),("call",(0-1)),("roam",(0-1)),("callsetup",(0-3))
HFPD: >> OK
HFPD: << AT+CMER=3,0,0,1
HFPD: >> OK
HFPD: << AT+CLIP=1
HFPD: >> ERROR
HFPD: << AT+CCWA=1
HFPD: >> ERROR
HFPD: << AT+CHLD=?
HFPD: >> ERROR
HFPD: << AT+CIND?
HFPD: AG 00:19:63B:02:F4: Connected
HFPD: >> +CIND: 4,3,0,1,1,1,0,0,0,0
HFPD: >> OK
HFPD: HCI Command status: 0x00 0x01 0x0803
HFPD: << ATD150;
HFPD: HCI Command status: 0x00 0x01 0x0804
HFPD: >> OK
HFPD: >> +CIEV: 10,2
HFPD: HCI Command status: 0x00 0x01 0x0409
HFPD: HCI Command status: 0x00 0x01 0x040f
HFPD: AudioGatewayStart: /net/sf/nohands/hfpd/<removed>
HFPD: ** OpLatency: primary open took 118ms
HFPD: ALSA play state: 2
HFPD: ALSA play state: 2
HFPD: ALSA rec state: 2
HFPD: ALSA rec state: 2
HFPD: Pump: packet size = 24
HFPD: Pump: bot packet size = 160
HFPD: Pump: bot input max fill = 320
HFPD: Pump: bot min fill = 320
HFPD: Pump: bot max fill = 640
HFPD: Pump: top packet size = 24
HFPD: Pump: top input max fill = 320
HFPD: Pump: top min fill = 320
HFPD: Pump: top max fill = 640
HFPD: Pump: watchdog timeout = 500
HFPD: ALSA play state: 2
HFPD: ALSA rec state: 2
HFPD: ** OpLatency: bottom EP start took 29ms
HFPD: ** OpLatency: ALSA SndPushOutput took 773ms
HFPD: ** OpLatency: ALSA async overall took 775ms
HFPD: SoundIoPump: bottom input underprocessed (0 < 1000)
HFPD: SoundIoPump: bottom output underprocessed (0 < 1000)
HFPD: SoundIoPump: top input underprocessed (0 < 1000)
HFPD: SoundIoPump: top output underprocessed (0 < 1000)
HFPD: >> +CIEV: 10,3
HFPD: ** OpLatency: ALSA SndPushOutput took 15ms
HFPD: ** OpLatency: ALSA async overall took 25ms
HFPD: ** OpLatency: ALSA SndPushInput took 116ms
HFPD: ** OpLatency: ALSA async overall took 121ms
HFPD: >> +CIEV: 8,1
HFPD: >> +CIEV: 10,0
HFPD: ** OpLatency: ALSA SndPushInput took 298ms
HFPD: ** OpLatency: ALSA async overall took 303ms
HFPD: ** OpLatency: ALSA SndPushInput took 672ms
HFPD: ** OpLatency: ALSA async overall took 677ms
HFPD: SoundIoPump: bottom input overprocessed (9440 > 8000)
HFPD: SoundIoPump: top input underprocessed (0 < 1000)
HFPD: SoundIoPump: top output underprocessed (0 < 1000)
HFPD: ** OpLatency: ALSA SndPushInput took 1386ms
HFPD: ** OpLatency: ALSA async overall took 1394ms
HFPD: SoundIoPump: bottom input overprocessed (11200 > 8000)
HFPD: SoundIoPump: bottom output underprocessed (320 < 1000)
HFPD: SoundIoPump: Top endpoint timeout
HFPD: SoundIoPump Stopped
HFPD: ** OpLatency: primary close took 24ms
HFPD: Sound card failed: SoundIoPump: Top endpoint timeout
HFPD: HCI Command status: 0x00 0x01 0x0406
HFPD: HCI Command status: 0x00 0x01 0x0803
HFPD: >> +CIEV: 8,0
Thank you very much for the work you are putting into hfp so we (tableters) can use it.
 
Posts: 76 | Thanked: 41 times | Joined on Nov 2008 @ Germany
#48
Okay, great news everybody!

I tried the latest version with access=thread and the feedback test is working now !!

I had to tune the Packet Interval a little to get it non-lagging (has to be >25ms), but after that it just works fine (and produces a nice echoing by the way (Don't hit me, I know that's not what we are after at the moment))

Strangely even the preferences window still works for me just fine.

Sadly, when I try to make a call in most cases the phone still gets disconnected (log attaced, seems similar to qwerty's).

Once it didn't and said it would transfer the audio but I wasn't able to hear audio from the tablet nor to hear myself in the phone I called. Also everything seemed to have crashed after the call had been initiated and hfp blocked the audio device (had to issue a "dsp_dld --enable-restart" to get it working again)
I tried but failed to reproduce that behavior...
I remember something like "3 times, you're out" from the output, but missed to capture it.

On the whole I think this looks very promising, thanks for the good work
Attached Files
File Type: txt hfp_call.txt (3.2 KB, 724 views)

Last edited by MrWeasel; 2008-12-14 at 11:36.
 

The Following 4 Users Say Thank You to MrWeasel For This Useful Post:
Posts: 9 | Thanked: 9 times | Joined on Nov 2008
#49
Originally Posted by qwerty12 View Post
The preferences window fails to work for me now:

'

So I edited ~/.hfconsole and put access=thread under [options] manually. When I dial, I get audio open for a few seconds (no sound) but then the phone reports "transferred to phone (as opposed to a headset)" and it says "primary sound card failure".
Hi querty12,

Is it possible that when you rebuilt from source and reinstalled, your running hfpd process was not restarted and didn't get updated?

Originally Posted by MrWeasel View Post
Okay, great news everybody!

I tried the latest version with access=thread and the feedback test is working now !!

I had to tune the Packet Interval a little to get it non-lagging (has to be >25ms), but after that it just works fine (and produces a nice echoing by the way (Don't hit me, I know that's not what we are after at the moment))

Strangely even the preferences window still works for me just fine.

Sadly, when I try to make a call in most cases the phone still gets disconnected (log attaced, seems similar to qwerty's).

Once it didn't and said it would transfer the audio but I wasn't able to hear audio from the tablet nor to hear myself in the phone I called. Also everything seemed to have crashed after the call had been initiated and hfp blocked the audio device (had to issue a "dsp_dld --enable-restart" to get it working again)
I tried but failed to reproduce that behavior...
I remember something like "3 times, you're out" from the output, but missed to capture it.
Hi MrWeasel,

Finally, some good news!! Even if it's only partly good. So, two problems:

1. Local audio gets into a bad state. Does simply killing hfpd fix this, or did you run that dsp_dld command after killing hfpd, in order to fix the state?

2. It looks like you got a spontaneous RFCOMM disconnection. So, now that the local audio at least pretends to work, let's focus on the apparent Bluetooth problems. Would you be willing to update your sources, rebuild and restart hfpd, run 'hcidump -t hci0' and post the output?

Heads up, I made "access=thread" the default now, it's not necessary in the configuration any more.
 
Posts: 76 | Thanked: 41 times | Joined on Nov 2008 @ Germany
#50
Originally Posted by samr7 View Post
1. Local audio gets into a bad state. Does simply killing hfpd fix this, or did you run that dsp_dld command after killing hfpd, in order to fix the state?
The last one. But I have to admit that I did not wait a reasonable time for hfp to come back. So I killed it and after that the restarted hfp wasn't able to open audio anymore.
I experienced this before when feedback wasn't working and it hung at this point, so I already knew what to do.
For me it doesn't feel like a serious problem, especially as I could not reproduce it. Maybe just a hickup after too many retries in a too short period of time.

Originally Posted by samr7 View Post
2. It looks like you got a spontaneous RFCOMM disconnection. So, now that the local audio at least pretends to work, let's focus on the apparent Bluetooth problems. Would you be willing to update your sources, rebuild and restart hfpd, run 'hcidump -t hci0' and post the output?
I also don't think that this disconnection is the main problem. It seems like the disconnection only happens because the tablet is not able to transfer/playback voice properly, so the phone decides to kick out it's handsfree device (when the disconnecion happens, the phone displays something like "audio playback through phone").
So maybe if we get this fixed, the disconnections will vanish, too.

Anyway, I'll try that hcidump thing tomorrow
 
Reply


 
Forum Jump


All times are GMT. The time now is 16:45.