kernel-packages team mailing list archive

Thread
Date
[Bug 1594002] [NEW] On Ubuntu touch, when receiving call while handsfree is connected, system behaves erratically and freezes

To: kernel-packages@xxxxxxxxxxxxxxxxxxx
From: AlainKnaff <1594002@xxxxxxxxxxxxxxxxxx>
Date: Sat, 18 Jun 2016 16:55:16 -0000
Reply-to: Bug 1594002 <1594002@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

This evening, I received a call in my car (Toyota Prius), while my
Aquaris E5 (Ubuntu touch) phone was connected via bluetooth handsfree
mode.

Ring tone sounded all right over the car's audio system, and call pick
up UI was displayed on central console.

However, the buttons would not react.

Buttons on the phone itself where reactive at first, but call still
wasn't connected. A short time after this phone's UI froze... and then
unfroze after a minute. Eventually two calls were shown, one being
active, and one "on hold". However, neither was connected (could not
hear other party / other party could not hear me). Eventually, other
party gave up, and tried again a minute later.

On that second call, I picked it up right on the phone's UI, and this
time it worked, with audio through car's system.

I found the following in my log:

Jun 18 12:57:18 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Default profile not connected, selecting off profile
Jun 18 12:58:20 localhost bluetoothd[667]: Unable to get io data for Phone Book Access: getpeername: Transport endpoint is not connected (107)

=> start of unrelated trip in the morning.


Jun 18 13:20:35 localhost bluetoothd[667]: Unable to get io data for hfp_ag: getpeername: Transport endpoint is not connected (107)

=> end of unrelated trip in the morning

Jun 18 17:47:34 localhost bluetoothd[667]: Unable to get io data for Phone Book Access: getpeername: Transport endpoint is not connected (107)
Jun 18 17:47:19 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Default profile not connected, selecting off profile

=> start of trip in the evening, during which I received the call.


Jun 18 17:49:27 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: SCO stream went down
Jun 18 17:50:07 localhost bluetoothd[667]: Unable to get io data for hfp_ag: getpeername: Transport endpoint is not connected (107)
Jun 18 17:50:07 localhost pulseaudio[2198]: message repeated 622601 times: [ [pulseaudio] module-bluez5-device.c: SCO stream went down]
Jun 18 17:50:12 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Default profile not connected, selecting off profile
Jun 18 17:50:45 localhost bluetoothd[667]: Unable to get io data for Phone Book Access: getpeername: Transport endpoint is not connected (107)
Jun 18 17:51:11 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Can't resume SCO over PCM

=> the call

Jun 18 18:16:01 localhost bluetoothd[667]: Unable to get io data for
hfp_ag: getpeername: Transport endpoint is not connected (107)

=> end of trip

/var/log/auth.log had the following messages about bluez (a
...
auth.log:Jun 18 17:15:49 localhost dbus[621]: message repeated 7 times: [ [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")]
auth.log:Jun 18 17:19:40 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
auth.log:Jun 18 17:19:40 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
auth.log:Jun 18 17:49:07 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
auth.log:Jun 18 17:49:27 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
auth.log:Jun 18 17:49:46 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
auth.log:Jun 18 17:49:46 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
auth.log:Jun 18 17:49:47 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
auth.log:Jun 18 17:49:48 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
auth.log:Jun 18 17:49:48 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
auth.log:Jun 18 17:50:25 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
...

These happened all through the day, even when not even in my car.


1) root@alains-pocket-penguin:/var/log# dpkg -S /usr/sbin/bluetoothd
bluez: /usr/sbin/bluetoothd
2) root@alains-pocket-penguin:/var/log# lsb_release -rd
Description:    Ubuntu 15.04
Release:        15.04
root@alains-pocket-penguin:/var/log# apt-cache policy bluez
bluez:
  Installed: 5.37-0ubuntu5~overlay1
  Candidate: 5.37-0ubuntu5~overlay1
  Version table:
 *** 5.37-0ubuntu5~overlay1 0
       1001 http://ppa.launchpad.net/ci-train-ppa-service/stable-snapshot/ubuntu/ vivid/main armhf Packages
        100 /var/lib/dpkg/status
     4.101-0ubuntu25 0
        500 http://ports.ubuntu.com/ubuntu-ports/ vivid/main armhf Packages
3) What I expected to happen:
 - It should be possible to accept call using car's UI
 - Phone should not freeze under any circumstances
 - There should be understandable and easy to find logs
4) What heppened instead
 - Car's UI unreactive
 - Attempting to take the call using phone's UI just froze and confused the system for a while
 - Logs are vague and not really clear about what happened.

** Affects: bluez (Ubuntu)
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Kernel
Packages, which is subscribed to bluez in Ubuntu.
https://bugs.launchpad.net/bugs/1594002

Title:
  On Ubuntu touch, when receiving call while handsfree is connected,
  system behaves erratically and freezes

Status in bluez package in Ubuntu:
  New

Bug description:
  This evening, I received a call in my car (Toyota Prius), while my
  Aquaris E5 (Ubuntu touch) phone was connected via bluetooth handsfree
  mode.

  Ring tone sounded all right over the car's audio system, and call pick
  up UI was displayed on central console.

  However, the buttons would not react.

  Buttons on the phone itself where reactive at first, but call still
  wasn't connected. A short time after this phone's UI froze... and then
  unfroze after a minute. Eventually two calls were shown, one being
  active, and one "on hold". However, neither was connected (could not
  hear other party / other party could not hear me). Eventually, other
  party gave up, and tried again a minute later.

  On that second call, I picked it up right on the phone's UI, and this
  time it worked, with audio through car's system.

  I found the following in my log:

  Jun 18 12:57:18 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Default profile not connected, selecting off profile
  Jun 18 12:58:20 localhost bluetoothd[667]: Unable to get io data for Phone Book Access: getpeername: Transport endpoint is not connected (107)

  => start of unrelated trip in the morning.

  
  Jun 18 13:20:35 localhost bluetoothd[667]: Unable to get io data for hfp_ag: getpeername: Transport endpoint is not connected (107)

  => end of unrelated trip in the morning

  Jun 18 17:47:34 localhost bluetoothd[667]: Unable to get io data for Phone Book Access: getpeername: Transport endpoint is not connected (107)
  Jun 18 17:47:19 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Default profile not connected, selecting off profile

  => start of trip in the evening, during which I received the call.

  
  Jun 18 17:49:27 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: SCO stream went down
  Jun 18 17:50:07 localhost bluetoothd[667]: Unable to get io data for hfp_ag: getpeername: Transport endpoint is not connected (107)
  Jun 18 17:50:07 localhost pulseaudio[2198]: message repeated 622601 times: [ [pulseaudio] module-bluez5-device.c: SCO stream went down]
  Jun 18 17:50:12 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Default profile not connected, selecting off profile
  Jun 18 17:50:45 localhost bluetoothd[667]: Unable to get io data for Phone Book Access: getpeername: Transport endpoint is not connected (107)
  Jun 18 17:51:11 localhost pulseaudio[2198]: [pulseaudio] module-bluez5-device.c: Can't resume SCO over PCM

  => the call

  Jun 18 18:16:01 localhost bluetoothd[667]: Unable to get io data for
  hfp_ag: getpeername: Transport endpoint is not connected (107)

  => end of trip

  /var/log/auth.log had the following messages about bluez (a
  ...
  auth.log:Jun 18 17:15:49 localhost dbus[621]: message repeated 7 times: [ [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")]
  auth.log:Jun 18 17:19:40 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
  auth.log:Jun 18 17:19:40 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
  auth.log:Jun 18 17:49:07 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
  auth.log:Jun 18 17:49:27 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
  auth.log:Jun 18 17:49:46 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
  auth.log:Jun 18 17:49:46 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
  auth.log:Jun 18 17:49:47 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
  auth.log:Jun 18 17:49:48 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
  auth.log:Jun 18 17:49:48 localhost dbus[621]: [system] Rejected send message, 4 matched rules; type="method_return", sender=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.6" (uid=0 pid=761 comm="/usr/bin/powerd ")
  auth.log:Jun 18 17:50:25 localhost dbus[621]: [system] Rejected send message, 5 matched rules; type="method_return", sender=":1.51" (uid=32011 pid=2198 comm="pulseaudio --start --log-target=syslog ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.21" (uid=0 pid=1910 comm="ofonod -P provision,udev*,dun*,smart*,hfp_bluez5,s")
  ...

  These happened all through the day, even when not even in my car.

  
  1) root@alains-pocket-penguin:/var/log# dpkg -S /usr/sbin/bluetoothd
  bluez: /usr/sbin/bluetoothd
  2) root@alains-pocket-penguin:/var/log# lsb_release -rd
  Description:    Ubuntu 15.04
  Release:        15.04
  root@alains-pocket-penguin:/var/log# apt-cache policy bluez
  bluez:
    Installed: 5.37-0ubuntu5~overlay1
    Candidate: 5.37-0ubuntu5~overlay1
    Version table:
   *** 5.37-0ubuntu5~overlay1 0
         1001 http://ppa.launchpad.net/ci-train-ppa-service/stable-snapshot/ubuntu/ vivid/main armhf Packages
          100 /var/lib/dpkg/status
       4.101-0ubuntu25 0
          500 http://ports.ubuntu.com/ubuntu-ports/ vivid/main armhf Packages
  3) What I expected to happen:
   - It should be possible to accept call using car's UI
   - Phone should not freeze under any circumstances
   - There should be understandable and easy to find logs
  4) What heppened instead
   - Car's UI unreactive
   - Attempting to take the call using phone's UI just froze and confused the system for a while
   - Logs are vague and not really clear about what happened.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/bluez/+bug/1594002/+subscriptions
Follow ups

[Bug 1594002] Re: On Ubuntu touch, when receiving call while handsfree is connected, system behaves erratically and freezes
From: Launchpad Bug Tracker, 2016-06-27