[Gta04-owner] [QtMoko] no sound during call (GTA04a3, QtMv48)

Neil Jerram neil at ossau.homelinux.net
Wed Oct 17 00:16:34 CEST 2012


Neil Jerram <neil at ossau.homelinux.net> writes:

> I think voice notes are flaky for me too.
[...]
>> Oct 6 01:07:13 neo kernel: [ 1157.022979] twl4030-codec twl4030-codec:
>> operation mode cannot be changed on-the-fly
>
> I have occurrences of that in my logs too.  It appears always to occur
> in this combination:
>
> Oct  6 16:55:09 neo kernel: [13816.386840] twl4030-codec twl4030-codec: operation mode cannot be changed on-the-fly
> Oct  6 16:55:09 neo Qtopia: alsactl returned  "alsactl: set_control:1388: Cannot write control '2:0:0:Codec Operation Mode:0' : Device or resource busy
> Oct  6 16:55:09 neo Qtopia: " , running kill-snd-card-users.sh 
> Oct  6 16:55:10 neo Qtopia: killing 1652

Here's an A3 patch that handles that codec error more gracefully, and
appears to improve voice notes and media playback for me.  A fairly full
description is in the patch itself.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0001-GTA04A3-Allow-Cannot-write-control-2-0-0-Codec-Opera.patch
Type: text/x-diff
Size: 5370 bytes
Desc: not available
URL: <http://lists.goldelico.com/pipermail/gta04-owner/attachments/20121016/e7e6dcfb/attachment-0001.bin>
-------------- next part --------------

There's plenty more still to understand and fix though: at least one
QtMoko and one kernel problem.  Here's an annotated log showing several
issues from my last hour...

Oct 16 22:09:35 neo syslogd 1.5.0#6: restart.
Oct 16 22:09:35 neo kernel: klogd 1.5.0#6, log source = /proc/kmsg started.
[... booting up ...]
Oct 16 22:09:36 neo kernel: [   14.388397] Bluetooth: RFCOMM socket layer initialized
Oct 16 22:09:36 neo kernel: [   14.393981] Bluetooth: RFCOMM ver 1.11

I plugged the headphones in...

Oct 16 22:09:49 neo Qtopia: AudioState :  Trying to set profile to: "Headphone" 
Oct 16 22:09:49 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:09:49 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:09:49 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:09:49 neo Qtopia: AudioState :  SpeakerAudioState::leave() 
Oct 16 22:09:49 neo Qtopia: AudioState :  HeadsetAudioState::enter() isPhone false 
Oct 16 22:09:49 neo Qtopia: AudioState :  echo  1  >  /sys/devices/virtual/gpio/gpio55/value 
Oct 16 22:09:49 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/headset.state", "restore") 
Oct 16 22:09:50 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:09:50 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:09:50 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:09:50 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:09:50 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:09:50 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:09:50 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:09:50 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:09:50 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 

Music playing happily for about a minute, but then...

Oct 16 22:10:48 neo Qtopia: AudioState :  Trying to set profile to: "MediaSpeaker" 
Oct 16 22:10:48 neo Qtopia: AudioState :  SpeakerAudioState::enter() isPhone false 
Oct 16 22:10:48 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:10:48 neo Qtopia:  :  alsactl stderr (ok):  "alsactl: set_control:1388: Cannot write control '2:0:0:Codec Operation Mode:0' : Device or resource busy" 
Oct 16 22:10:48 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:10:48 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:10:48 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:10:48 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:10:48 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:10:48 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:10:48 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:10:48 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:10:48 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:10:48 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:10:48 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:10:49 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 
Oct 16 22:10:49 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:10:49 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:10:49 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:10:49 neo Qtopia: AudioState :  SpeakerAudioState::leave() 
Oct 16 22:10:49 neo Qtopia: AudioState :  HeadsetAudioState::enter() isPhone false 
Oct 16 22:10:49 neo Qtopia: AudioState :  echo  1  >  /sys/devices/virtual/gpio/gpio55/value 
Oct 16 22:10:49 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/headset.state", "restore") 
Oct 16 22:10:49 neo Qtopia:  :  alsactl stderr (ok):  "alsactl: set_control:1388: Cannot write control '2:0:0:Codec Operation Mode:0' : Device or resource busy" 
Oct 16 22:10:49 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:10:49 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:10:49 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:10:49 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:10:49 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:10:49 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:10:49 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:10:49 neo Qtopia: AudioState :  Trying to set profile to: "Headphone" 
Oct 16 22:10:49 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:10:49 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 

I'm pretty sure I didn't actually do anything that should have caused
the above transitions; I believe I was just playing with the playlist.
But something triggered those transitions, and now I no longer have a
working media player.

Oct 16 22:11:09 neo Qtopia: AudioState :  Handsfree audio gateway:  QBluetoothAudioGateway(0x1975a40) 
Oct 16 22:11:09 neo Qtopia: AudioState :  Headset audio gateway:  QBluetoothAudioGateway(0x1973888) 
Oct 16 22:11:09 neo Qtopia: AudioState :  No current audio gateway found 
Oct 16 22:11:09 neo Qtopia: AudioState :  Handsfree audio gateway:  QBluetoothAudioGateway(0x19771b0) 
Oct 16 22:11:09 neo Qtopia: AudioState :  Headset audio gateway:  QBluetoothAudioGateway(0x1952f68) 
Oct 16 22:11:09 neo Qtopia: AudioState :  No current audio gateway found 
Oct 16 22:11:09 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:11:09 neo Qtopia: AudioState :  Finding highest priority state for domain: "Media" and capability: 2 
Oct 16 22:11:09 neo Qtopia: AudioState :  AudioState found was: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) 
Oct 16 22:11:09 neo Qtopia: AudioState :  HeadsetAudioState::enter() isPhone false 
Oct 16 22:11:09 neo Qtopia: AudioState :  echo  1  >  /sys/devices/virtual/gpio/gpio55/value 
Oct 16 22:11:09 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/headset.state", "restore") 
Oct 16 22:11:09 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:11:09 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:11:09 neo Qtopia: AudioState :  ====== USER startAudio()     QAudioInterface(0x193caa8) 
Oct 16 22:11:09 neo Qtopia: AudioState :  QAudioInterfaceServer() FAILED! trying to listen for Client instances 
Oct 16 22:11:10 neo Qtopia: AudioState :  QLocalSocket::ConnectionRefusedError 
Oct 16 22:11:41 neo last message repeated 62 times
Oct 16 22:12:13 neo last message repeated 65 times

So this looks like a QtMoko-level issue between the media player and the
sound server.  I think I now tried killing and restarting the media
player a couple of times - but that hits the 'ConnectionRefusedError's below.

Oct 16 22:12:14 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:12:14 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:14 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:12:14 neo Qtopia: AudioState :  Finding highest priority state for domain: "Media" and capability: 2 
Oct 16 22:12:14 neo Qtopia: AudioState :  AudioState found was: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) 
Oct 16 22:12:14 neo Qtopia: AudioState :  SpeakerAudioState::enter() isPhone false 
Oct 16 22:12:14 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:12:14 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:12:14 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:12:14 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:12:14 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:12:14 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:14 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:12:14 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:12:14 neo Qtopia: AudioState :  Trying to set profile to: "MediaSpeaker" 
Oct 16 22:12:14 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:12:14 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 
Oct 16 22:12:14 neo Qtopia: AudioState :  QLocalSocket::ConnectionRefusedError 
Oct 16 22:12:20 neo last message repeated 12 times
Oct 16 22:12:20 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:12:20 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:20 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:12:20 neo Qtopia: AudioState :  SpeakerAudioState::leave() 
Oct 16 22:12:20 neo Qtopia: AudioState :  HeadsetAudioState::enter() isPhone false 
Oct 16 22:12:20 neo Qtopia: AudioState :  echo  1  >  /sys/devices/virtual/gpio/gpio55/value 
Oct 16 22:12:20 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/headset.state", "restore") 
Oct 16 22:12:20 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:12:20 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:12:20 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:12:20 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:12:20 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:20 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:12:20 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:12:20 neo Qtopia: AudioState :  Trying to set profile to: "Headphone" 
Oct 16 22:12:20 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:12:20 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 
Oct 16 22:12:21 neo Qtopia: AudioState :  QLocalSocket::ConnectionRefusedError 
Oct 16 22:12:39 neo last message repeated 37 times
Oct 16 22:12:39 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:12:39 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:39 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:12:39 neo Qtopia: AudioState :  SpeakerAudioState::enter() isPhone false 
Oct 16 22:12:39 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:12:40 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:12:40 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:12:40 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:12:40 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:12:40 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:40 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:12:40 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:12:40 neo Qtopia: AudioState :  Trying to set profile to: "MediaSpeaker" 
Oct 16 22:12:40 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:12:40 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 
Oct 16 22:12:40 neo Qtopia: AudioState :  QLocalSocket::ConnectionRefusedError 
Oct 16 22:12:40 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:12:40 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:40 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:12:40 neo Qtopia: AudioState :  SpeakerAudioState::leave() 
Oct 16 22:12:40 neo Qtopia: AudioState :  HeadsetAudioState::enter() isPhone false 
Oct 16 22:12:40 neo Qtopia: AudioState :  echo  1  >  /sys/devices/virtual/gpio/gpio55/value 
Oct 16 22:12:40 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/headset.state", "restore") 
Oct 16 22:12:40 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:12:40 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:12:40 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:12:40 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() true 
Oct 16 22:12:40 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:12:40 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: true 
Oct 16 22:12:40 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:12:40 neo Qtopia: AudioState :  Trying to set profile to: "Headphone" 
Oct 16 22:12:40 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) false 
Oct 16 22:12:40 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 
Oct 16 22:12:40 neo Qtopia: AudioState :  QLocalSocket::ConnectionRefusedError 
Oct 16 22:13:09 neo last message repeated 58 times
Oct 16 22:13:11 neo Qtopia: AudioState :  Handsfree audio gateway:  QBluetoothAudioGateway(0xd9fa40) 
Oct 16 22:13:11 neo Qtopia: AudioState :  Headset audio gateway:  QBluetoothAudioGateway(0xd9d888) 
Oct 16 22:13:11 neo Qtopia: AudioState :  No current audio gateway found 
Oct 16 22:13:11 neo Qtopia: AudioState :  Handsfree audio gateway:  QBluetoothAudioGateway(0xda11b0) 
Oct 16 22:13:11 neo Qtopia: AudioState :  Headset audio gateway:  QBluetoothAudioGateway(0xd7cf68) 
Oct 16 22:13:11 neo Qtopia: AudioState :  No current audio gateway found 
Oct 16 22:13:11 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:13:12 neo Qtopia: AudioState :  Finding highest priority state for domain: "Media" and capability: 2 
Oct 16 22:13:12 neo Qtopia: AudioState :  AudioState found was: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) 
Oct 16 22:13:12 neo Qtopia: AudioState :  HeadsetAudioState::enter() isPhone false 
Oct 16 22:13:12 neo Qtopia: AudioState :  echo  1  >  /sys/devices/virtual/gpio/gpio55/value 
Oct 16 22:13:12 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/headset.state", "restore") 
Oct 16 22:13:12 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:13:12 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:13:12 neo Qtopia: AudioState :  ====== USER startAudio()     QAudioInterface(0xd66aa8) 
Oct 16 22:13:12 neo Qtopia: AudioState :  QAudioInterfaceServer() FAILED! trying to listen for Client instances 
Oct 16 22:13:13 neo Qtopia: AudioState :  QLocalSocket::ConnectionRefusedError 
Oct 16 22:13:33 neo last message repeated 40 times
Oct 16 22:13:33 neo Qtopia: QProcess: Destroyed while process is still running.
Oct 16 22:13:34 neo Qtopia: Unable to send SIGTERM No such process
Oct 16 22:13:35 neo Qtopia: Unable to send SIGKILL No such process

Now I restart QtMoko.

Oct 16 22:13:35 neo Qtopia: NeoKbdDriverPlugin:create()
Oct 16 22:13:35 neo Qtopia: Before call NeoKbdHandler()
Oct 16 22:13:35 neo Qtopia: -34110 0 
Oct 16 22:13:35 neo Qtopia: Gta04ModemService::constructor 
Oct 16 22:13:36 neo Qtopia: AudioState :  NeoVolumeService::NeoVolumeService() 
Oct 16 22:13:36 neo Qtopia: 0 
Oct 16 22:13:36 neo Qtopia: AudioState :  void NeoVolumeService::initVolumes() 
Oct 16 22:13:37 neo Qtopia: QString::arg: Argument missing: "1 missed", @/Communications/Calls/MissedCalls
Oct 16 22:13:37 neo Qtopia: QString::arg: Argument missing: "1 new", @/Communications/Messages/NewMessages
Oct 16 22:13:37 neo Qtopia: AudioState :  Handsfree audio gateway:  QBluetoothAudioGateway(0x1c253d8) 
Oct 16 22:13:37 neo Qtopia: AudioState :  Headset audio gateway:  QBluetoothAudioGateway(0x1c227f0) 
Oct 16 22:13:37 neo Qtopia: AudioState :  No current audio gateway found 
Oct 16 22:13:37 neo Qtopia: AudioState :  Handsfree audio gateway:  QBluetoothAudioGateway(0x1c26bb0) 
Oct 16 22:13:37 neo Qtopia: AudioState :  Headset audio gateway:  QBluetoothAudioGateway(0x1c02ef8) 
Oct 16 22:13:37 neo Qtopia: AudioState :  No current audio gateway found 
Oct 16 22:13:37 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:13:41 neo Qtopia: AudioState :  Finding highest priority state for domain: "Media" and capability: 2 
Oct 16 22:13:41 neo Qtopia: AudioState :  AudioState found was: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) 
Oct 16 22:13:41 neo Qtopia: AudioState :  SpeakerAudioState::enter() isPhone false 
Oct 16 22:13:41 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:13:41 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:13:41 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:13:41 neo Qtopia: AudioState :  ====== USER startAudio()     QAudioInterface(0x1beeb68) 
Oct 16 22:13:42 neo Qtopia: AudioState :  QAudioInterfacePrivate() connected 
Oct 16 22:13:42 neo Qtopia: AudioState :   S->C  "--- ACTIVE"          QLocalSocket(0x1c3f438) 
Oct 16 22:13:42 neo Qtopia: AudioState :  data from server, msg= "--- ACTIVE "      QAudioInterfacePrivate(0x1c2fdc0) 
Oct 16 22:13:42 neo Qtopia: AudioState :   S<-C  "--- DOMAIN MediaServer"        QAudioInterfacePrivate(0x1c2fdc0) 
Oct 16 22:13:42 neo Qtopia: AudioState :   S->C  "--- ACK"          QLocalSocket(0x1c3f438) 
Oct 16 22:13:42 neo Qtopia: AudioState :  data from server, msg= "--- ACK "      QAudioInterfacePrivate(0x1c2fdc0) 
Oct 16 22:13:42 neo Qtopia: AudioState :   S<-C  "--- PLAY"        QAudioInterfacePrivate(0x1c2fdc0) 
Oct 16 22:13:42 neo Qtopia: AudioState :   S->C  "--- READY"          QLocalSocket(0x1c3f438) 
Oct 16 22:13:42 neo Qtopia: AudioState :  data from server, msg= "--- READY "      QAudioInterfacePrivate(0x1c2fdc0) 
Oct 16 22:13:42 neo Qtopia: AudioState :  Finding highest priority state for domain: "Media" and capability: 2 
Oct 16 22:13:42 neo Qtopia: AudioState :  AudioState found was: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) 
Oct 16 22:13:42 neo Qtopia: AudioState :  SpeakerAudioState::leave() 
Oct 16 22:13:42 neo Qtopia: AudioState :  SpeakerAudioState::enter() isPhone false 
Oct 16 22:13:42 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:13:42 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:13:42 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:13:42 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 

Media playback is now working again.

Oct 16 22:14:41 neo Qtopia: AudioState :  Trying to set profile to: "MediaSpeaker" 
[...]
Oct 16 22:15:33 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 

Now there's an incoming call.  I think the ringtone starts about now,
with the previous playing music being automatically stopped.

Oct 16 22:21:46 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:21:46 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:21:46 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:21:46 neo Qtopia: AudioState :  SpeakerAudioState::enter() isPhone false 
Oct 16 22:21:46 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:21:46 neo Qtopia:  :  alsactl stderr (ok):  "alsactl: set_control:1388: Cannot write control '2:0:0:Codec Operation Mode:0' : Device or resource busy" 
Oct 16 22:21:46 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:21:46 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "Headset" , "Headphones" , 50 ) QFlags(0x1|0x2) 
Oct 16 22:21:46 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:21:46 neo Qtopia: AudioState :  void HeadsetAudioState::onHeadsetModified() false 
Oct 16 22:21:46 neo Qtopia: AudioState :  AudioStateManager::notifyStateAvailable: 
Oct 16 22:21:46 neo Qtopia: AudioState :  State availability for: QAudioStateInfo( true , "Phone" , "Headset" , "Headphones" , 50 ) changed, now is: false 
Oct 16 22:21:46 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:21:46 neo Qtopia: AudioState :  Trying to set profile to: "MediaSpeaker" 
Oct 16 22:21:46 neo Qtopia: AudioState :  void NeoVolumeService::setAmp(bool) true 
Oct 16 22:21:46 neo Qtopia: AudioState :  void QAudioInterface::availabilityChanged() 

Now answering the call and switching to GSM state:

Oct 16 22:21:48 neo Qtopia: AudioState :  Finding highest priority state for domain: "Phone" and capability: 2 
Oct 16 22:21:48 neo Qtopia: AudioState :  AudioState found was: QAudioStateInfo( true , "Phone" , "PhoneEarpiece" , "Earpiece" , 100 ) 
Oct 16 22:21:48 neo Qtopia: AudioState :  SpeakerAudioState::leave() 
Oct 16 22:21:48 neo Qtopia: AudioState :  EarpieceAudioState::enter() isPhone true 
Oct 16 22:21:48 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/gsmearpiece.state", "restore") 
Oct 16 22:21:48 neo Qtopia: AudioState :  starting gsm-voice-routing pid  1144 
Oct 16 22:21:48 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:21:48 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:21:48 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Phone" , "PhoneEarpiece" , "Earpiece" , 100 ) QFlags(0x2) 
Oct 16 22:21:48 neo Qtopia: gsm-voice-routing started
Oct 16 22:21:48 neo Qtopia: voice routing started
Oct 16 22:23:45 neo Qtopia: X509 error  0  depth  11885208 
Oct 16 22:23:45 neo Qtopia: Encrypted connect warnings: "'The host name did not match any of the valid hosts for this certificate', 'No error'" 
Oct 16 22:33:43 neo Qtopia: p0 (default): underrun occured: Broken pipe
Oct 16 22:33:43 neo Qtopia: X509 error  0  depth  10632464 
Oct 16 22:33:44 neo Qtopia: Encrypted connect warnings: "'The host name did not match any of the valid hosts for this certificate', 'No error'" 
Oct 16 22:35:03 neo Qtopia: Unable to complete service: "NewEmailArrival" - "timeout" 
Oct 16 22:43:38 neo Qtopia: X509 error  0  depth  13879048 
Oct 16 22:43:39 neo Qtopia: Encrypted connect warnings: "'The host name did not match any of the valid hosts for this certificate', 'No error'" 
Oct 16 22:44:57 neo Qtopia: Unable to complete service: "NewEmailArrival" - "timeout" 

The call is now ending.  I think the following QAudioOutput::open()
calls might be QtMoko trying to restart the music playing, and I guess
that the reason for them failing is that the GTA04A4 voice routing
program is still running and so hasn't released the sound devices.

Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 1 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 2 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 3 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 4 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 5 
Oct 16 22:45:59 neo Qtopia: QAudioOuput: snd_pcm_open: error -16
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 1 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 2 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 3 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 4 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 5 
Oct 16 22:45:59 neo Qtopia: QAudioOuput: snd_pcm_open: error -16
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 1 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 2 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 3 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 4 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 5 
Oct 16 22:45:59 neo Qtopia: QAudioOuput: snd_pcm_open: error -16
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 1 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 2 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 3 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 4 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 5 
Oct 16 22:45:59 neo Qtopia: QAudioOuput: snd_pcm_open: error -16
Oct 16 22:45:59 neo Qtopia: AudioState :  Finding highest priority state for domain: "Media" and capability: 2 
Oct 16 22:45:59 neo Qtopia: AudioState :  AudioState found was: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) 
Oct 16 22:45:59 neo Qtopia: AudioState :  EarpieceAudioState::leave() 
Oct 16 22:45:59 neo Qtopia: AudioState :  terminating gsm-voice-routing pid  1144 
Oct 16 22:45:59 neo Qtopia: gsm-voice-routing ending - signal 15

Now the voice routing program has ended.

Oct 16 22:45:59 neo Qtopia: AudioState :  SpeakerAudioState::enter() isPhone false 
Oct 16 22:45:59 neo Qtopia: AudioState :  alsactl  ("-f", "/opt/qtmoko/etc/alsa/speaker.state", "restore") 
Oct 16 22:45:59 neo Qtopia: QAudioOutput::open() err= -16 , count= 1 
Oct 16 22:45:59 neo Qtopia:  :  alsactl stderr (ok):  "alsactl: set_control:1388: Cannot write control '2:0:0:Codec Operation Mode:0' : Device or resource busy" 
Oct 16 22:45:59 neo Qtopia: AudioState :  QAudioStateManager::stateChanged 
Oct 16 22:45:59 neo Qtopia: AudioState :  From State: QAudioStateInfo( true , "Phone" , "PhoneEarpiece" , "Earpiece" , 100 ) QFlags(0x2) 
Oct 16 22:45:59 neo Qtopia: AudioState :  To State: QAudioStateInfo( true , "Media" , "MediaSpeaker" , "Speaker" , 100 ) QFlags(0x2) 
Oct 16 22:46:19 neo kernel: [ 2260.901916] [<c0012250>] (unwind_backtrace+0x0/0xe0) from [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c)
Oct 16 22:46:19 neo kernel: [ 2260.913909] [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c) from [<c030b708>] (omap_pcm_hw_free+0x28/0x54)
Oct 16 22:46:19 neo kernel: [ 2260.925598] [<c030b708>] (omap_pcm_hw_free+0x28/0x54) from [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8)
Oct 16 22:46:19 neo kernel: [ 2260.936492] [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8) from [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4)
Oct 16 22:46:19 neo kernel: [ 2260.948333] [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4) from [<c02e0e64>] (snd_pcm_release+0x28/0x6c)
Oct 16 22:46:19 neo kernel: [ 2260.960144] [<c02e0e64>] (snd_pcm_release+0x28/0x6c) from [<c00a7c94>] (fput+0x104/0x23c)
Oct 16 22:46:19 neo kernel: [ 2260.970214] [<c00a7c94>] (fput+0x104/0x23c) from [<c00a4adc>] (filp_close+0x70/0x7c)
Oct 16 22:46:19 neo kernel: [ 2260.979797] [<c00a4adc>] (filp_close+0x70/0x7c) from [<c00a4bb0>] (sys_close+0xc8/0x120)
Oct 16 22:46:19 neo kernel: [ 2260.990112] [<c00a4bb0>] (sys_close+0xc8/0x120) from [<c000d800>] (ret_fast_syscall+0x0/0x30)
Oct 16 22:46:49 neo kernel: [ 2291.042419] [<c0012250>] (unwind_backtrace+0x0/0xe0) from [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c)
Oct 16 22:46:49 neo kernel: [ 2291.054321] [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c) from [<c030b708>] (omap_pcm_hw_free+0x28/0x54)
Oct 16 22:46:49 neo kernel: [ 2291.065917] [<c030b708>] (omap_pcm_hw_free+0x28/0x54) from [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8)
Oct 16 22:46:49 neo kernel: [ 2291.076965] [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8) from [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4)
Oct 16 22:46:49 neo kernel: [ 2291.088653] [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4) from [<c02e0e64>] (snd_pcm_release+0x28/0x6c)
Oct 16 22:46:49 neo kernel: [ 2291.100524] [<c02e0e64>] (snd_pcm_release+0x28/0x6c) from [<c00a7c94>] (fput+0x104/0x23c)
Oct 16 22:46:49 neo kernel: [ 2291.111297] [<c00a7c94>] (fput+0x104/0x23c) from [<c00a4adc>] (filp_close+0x70/0x7c)
Oct 16 22:46:49 neo kernel: [ 2291.121459] [<c00a4adc>] (filp_close+0x70/0x7c) from [<c00a4bb0>] (sys_close+0xc8/0x120)
Oct 16 22:46:49 neo kernel: [ 2291.131347] [<c00a4bb0>] (sys_close+0xc8/0x120) from [<c000d800>] (ret_fast_syscall+0x0/0x30)
Oct 16 22:47:19 neo kernel: [ 2321.222076] [<c0012250>] (unwind_backtrace+0x0/0xe0) from [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c)
Oct 16 22:47:19 neo kernel: [ 2321.232940] [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c) from [<c030b708>] (omap_pcm_hw_free+0x28/0x54)
Oct 16 22:47:19 neo kernel: [ 2321.243347] [<c030b708>] (omap_pcm_hw_free+0x28/0x54) from [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8)
Oct 16 22:47:19 neo kernel: [ 2321.253387] [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8) from [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4)
Oct 16 22:47:19 neo kernel: [ 2321.264221] [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4) from [<c02e0e64>] (snd_pcm_release+0x28/0x6c)
Oct 16 22:47:19 neo kernel: [ 2321.275085] [<c02e0e64>] (snd_pcm_release+0x28/0x6c) from [<c00a7c94>] (fput+0x104/0x23c)
Oct 16 22:47:19 neo kernel: [ 2321.284179] [<c00a7c94>] (fput+0x104/0x23c) from [<c00a4adc>] (filp_close+0x70/0x7c)
Oct 16 22:47:19 neo kernel: [ 2321.292846] [<c00a4adc>] (filp_close+0x70/0x7c) from [<c00a4bb0>] (sys_close+0xc8/0x120)
Oct 16 22:47:19 neo kernel: [ 2321.301849] [<c00a4bb0>] (sys_close+0xc8/0x120) from [<c000d800>] (ret_fast_syscall+0x0/0x30)
Oct 16 22:47:49 neo kernel: [ 2351.339050] [<c0012250>] (unwind_backtrace+0x0/0xe0) from [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c)
Oct 16 22:47:49 neo kernel: [ 2351.378631] [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c) from [<c030b708>] (omap_pcm_hw_free+0x28/0x54)
Oct 16 22:47:49 neo kernel: [ 2351.409881] [<c030b708>] (omap_pcm_hw_free+0x28/0x54) from [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8)
Oct 16 22:47:49 neo kernel: [ 2351.433410] [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8) from [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4)
Oct 16 22:47:49 neo kernel: [ 2351.456756] [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4) from [<c02e0e64>] (snd_pcm_release+0x28/0x6c)
Oct 16 22:47:49 neo kernel: [ 2351.476257] [<c02e0e64>] (snd_pcm_release+0x28/0x6c) from [<c00a7c94>] (fput+0x104/0x23c)
Oct 16 22:47:49 neo kernel: [ 2351.486450] [<c00a7c94>] (fput+0x104/0x23c) from [<c00a4adc>] (filp_close+0x70/0x7c)
Oct 16 22:47:49 neo kernel: [ 2351.495483] [<c00a4adc>] (filp_close+0x70/0x7c) from [<c00a4bb0>] (sys_close+0xc8/0x120)
Oct 16 22:47:49 neo kernel: [ 2351.504760] [<c00a4bb0>] (sys_close+0xc8/0x120) from [<c000d800>] (ret_fast_syscall+0x0/0x30)
Oct 16 22:48:19 neo kernel: [ 2381.565979] [<c0012250>] (unwind_backtrace+0x0/0xe0) from [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c)
Oct 16 22:48:19 neo kernel: [ 2381.576873] [<c0025e80>] (omap_dma_unlink_lch+0x6c/0x8c) from [<c030b708>] (omap_pcm_hw_free+0x28/0x54)
Oct 16 22:48:20 neo kernel: [ 2381.587280] [<c030b708>] (omap_pcm_hw_free+0x28/0x54) from [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8)
Oct 16 22:48:20 neo kernel: [ 2381.597412] [<c03070c4>] (soc_pcm_hw_free+0x88/0xd8) from [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4)
Oct 16 22:48:20 neo kernel: [ 2381.608276] [<c02e0ddc>] (snd_pcm_release_substream+0x44/0xa4) from [<c02e0e64>] (snd_pcm_release+0x28/0x6c)
Oct 16 22:48:20 neo kernel: [ 2381.619140] [<c02e0e64>] (snd_pcm_release+0x28/0x6c) from [<c00a7c94>] (fput+0x104/0x23c)
Oct 16 22:48:20 neo kernel: [ 2381.628814] [<c00a7c94>] (fput+0x104/0x23c) from [<c00a4adc>] (filp_close+0x70/0x7c)
Oct 16 22:48:20 neo kernel: [ 2381.643585] [<c00a4adc>] (filp_close+0x70/0x7c) from [<c00a4bb0>] (sys_close+0xc8/0x120)
Oct 16 22:48:20 neo kernel: [ 2381.653167] [<c00a4bb0>] (sys_close+0xc8/0x120) from [<c000d800>] (ret_fast_syscall+0x0/0x30)

And finally some of those kernel backtraces.  At this point I have no
sound at all until I reboot.

Regards,
        Neil


More information about the Gta04-owner mailing list