Delay of approx. 60 seconds when an outgoing call is innitiated by the IN CAR bluetooth system

Bug #1533716 reported by Uranicus
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Canonical System Image
Fix Released
Critical
John McAleely
bluez (Ubuntu)
Invalid
Undecided
Unassigned
bluez (Ubuntu RTM)
Invalid
Undecided
Unassigned
ofono (Ubuntu)
Fix Released
Critical
Simon Fels
ofono (Ubuntu RTM)
Fix Released
Critical
Simon Fels

Bug Description

My system:

current build number: 228
device name: krillin
channel: ubuntu-touch/rc-proposed/bq-aquaris.en
last update: 2016-01-13 08:28:26
version version: 228
version ubuntu: 20160113
version device: 20160108-efc96d8
version custom: 20151111--36-46-vivid

Since several days (not weeks, so something has changed in the last couple days!) I have the following situation with my BQ 4.5 in my car. When I initiate a call from the IN CAR system (where my phone is connected to) I experience sometimes the normal behaviour that the call is directly established.

Sometimes nothing happens. The call is not established and my in car system says that the attempt to carry out a call has failed (this message comes after approx. 15 seconds after initiation of the call).
Then approx. 60 seconds after the initiation of the call the call is all of a sudden established (without any further interaction). I currently was not able to find a logic in this. Here my "log"-file of what I did today:

-----

13.01.2016

9:00 h call initiated from car, call directly established
9:03 h call initiated from car (phone book), approx. 60 sec. delay between initiation and call being established
9:06 h call initiated from car, call directly established
9:09 h call initiated from car (phone book), approx. 60 sec. delay between initiation and call being established

9:26 h New pairing between phone and car, retry

9:30 h call initiated from car, call directly established
9:33 h call initiated from car (phone book), approx. 60 sec. delay between initiation and call being established
9:36 h call initiated from car, call directly established
9:39 h call initiated from car (phone book), approx. 60 sec. delay between initiation and call being established
9:42 h call initiated from car, call directly established
9:45 h call initiated from car, call directly established (this time again via phone book)
9:48 h call initiated from car (via voice command), approx. 60 sec. delay between initiation and call being established
9:52 h call initiated from phone itself, call established and correctly routed via car speaker

I have added the syslog, upstart-files to the bug report for further analysis.

Uranicus

Related branches

Revision history for this message
Uranicus (matthias.ritter) wrote :
Revision history for this message
Jean-Baptiste Lallement (jibel) wrote :

I can reproduce the problem with a Garmin Nüvi and latest krillin rc-proposed. It seems that the call is not initiated when the device is suspended. As soon as the device wakes up, the call starts.

Changed in canonical-devices-system-image:
importance: Undecided → Critical
milestone: none → ww02-2016
status: New → Confirmed
assignee: nobody → John McAleely (john.mcaleely)
Revision history for this message
Jean-Baptiste Lallement (jibel) wrote :

It's clearly a recent regression . I tried 6 times with krillin rc-proposed 220 (20160104) and couldn't reproduce the issue. Then upgraded to latest build (230) and reproduced the issue immediately.

tags: added: regression-proposed
tags: added: lt-blocker
Revision history for this message
Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in bluez (Ubuntu):
status: New → Confirmed
Revision history for this message
Jean-Baptiste Lallement (jibel) wrote :
Download full text (3.6 KiB)

Here is a syslog from krillin rc-proposed 230 when the problem is reproduced.
@20:18:20 the call is initiated from the BT device, the device wakes up and there is an ATD command to setup the call but immediately the device suspends again.

Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.068163][SPM] md_settle = 99, settle = 99
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.068163][SPM] sec = 5400, wakesrc = 0x3204564 (1)(1)
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.068163][SPM] wake up by CONN (0x80000c00)(0x400)(250871)
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.068163][SPM] event_reg = 0x90010000, isr = 0x10, r13 = 0xea060842
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.068163]wdt enable spm timer.....
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.068163][WDT] resume(1)
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.068169]Suspended for 0.000 seconds
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071005][MATV] resume
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071119]Mali<1>: Mali PM: mali_pm_resume
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071515][Serial_Core]: By pass Set termio
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071526][UART0] Resume(0)!
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071545][UART1] Resume(0)!
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071559]GPIO_UART_URXD3_PIN is not properly set p2
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071570][UART2] Resume(0)!
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071584]GPIO_UART_URXD4_PIN is not properly set p2
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.071595][UART3] Resume(0)!
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.258608]sd card rocr <0xc0ff8000>
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.262823][Reset and init thermal controller]
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.262852][PTP] PTP_INIT_02() start (ptp_level = 0x0).
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.262860][PTP] DCVOFFSETIN = 0xffffff2a
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.262867][PTP] AGEVOFFSETIN = 0x0
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.262884][PTP] PTP_MON_MODE() start (ptp_level = 0x0).
Jan 14 20:18:20 ubuntu-phablet ofonod[1923]: Server: < ATD0629161837;\r
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.263513]Restarting tasks ... done.
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.268147][pm_notifier_call_chain]: there are 4 notify callbacks, event = 4
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.268206]msdc: 0,mmc_schedule_delayed_work ret= 1
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.268264]msdc: 1,mmc_schedule_delayed_work ret= 1
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.268286]PM: suspend exit 2016-01-14 20:18:20.198010769 UTC
Jan 14 20:18:20 ubuntu-phablet kernel: [ 187.268514]PM: suspend entry 2016-01-14 20:18:20.198236077 UTC
...

Then nothing happens until 20:20:12 (112s) and the device finally wakes up, it makes the call and the display turns on.

Jan 14 20:20:12 ubuntu-phablet kernel: [ 187.553595]Restarting tasks ... done.
Jan 14 20:20:12 ubuntu-phablet kernel: [ 187.564436][pm_notifier_call_chain]: there are 4 notify callbacks, event = 4
Jan 14 20:20:12 ubuntu-phablet kernel: [ 187.564493]msdc: 0,mmc_schedule_delayed_work re...

Read more...

Changed in canonical-devices-system-image:
status: Confirmed → In Progress
Tony Espy (awe)
Changed in ofono (Ubuntu):
status: New → Confirmed
Changed in ofono (Ubuntu RTM):
status: New → In Progress
Changed in bluez (Ubuntu):
status: Confirmed → Invalid
Changed in bluez (Ubuntu RTM):
status: New → Invalid
Changed in ofono (Ubuntu):
assignee: nobody → Simon Fels (morphis)
Changed in ofono (Ubuntu RTM):
assignee: nobody → Simon Fels (morphis)
Tony Espy (awe)
Changed in ofono (Ubuntu RTM):
status: In Progress → Fix Committed
importance: Undecided → Critical
Changed in ofono (Ubuntu):
importance: Undecided → High
importance: High → Critical
status: Confirmed → Fix Committed
Revision history for this message
Łukasz Zemczak (sil2100) wrote :

This bug was fixed in the package ofono 1.17.bzr6910+15.04.20160115.3-0ubuntu1 in https://launchpad.net/~ci-train-ppa-service/+archive/ubuntu/stable-phone-overlay

---------------

ofono (1.17.bzr6910+15.04.20160115.3-0ubuntu1) vivid; urgency=medium

  [ Simon Fels ]
  [ Simon Fels]

  * voicecall: acquire wakelock when starting a HFP initated voicecall
    (LP: #1533716)
  * plugins: add android wakelock implementation
  * src: add wakelock abstraction

  [ CI Train Bot ]
  * No-change rebuild.

ofono (1.17.bzr6908+16.04.20151203-0ubuntu1) xenial; urgency=medium

  [ Tony Espy ]
  * Add unit test test-rilmodem-cs

  [ Simon Fels ]
  * voicecall: don't dereference a supplied null value

  [ Alfonso Sanchez-Beato ]
  * Support handling incoming calls for HFP + multi-SIM

  [ CI Train Bot ]
  * New rebuild forced.

 -- Tony Espy <email address hidden> Fri, 15 Jan 2016 17:37:10 +0000

Changed in ofono (Ubuntu RTM):
status: Fix Committed → Fix Released
Changed in canonical-devices-system-image:
status: In Progress → Fix Committed
Revision history for this message
Uranicus (matthias.ritter) wrote :

Dear all,

I have tested it today several times on:

current build number: 232
device name: krillin
channel: ubuntu-touch/rc-proposed/bq-aquaris.en
last update: 2016-01-16 08:03:38
version version: 232
version ubuntu: 20160116
version device: 20160108-efc96d8
version custom: 20160111-926-36--vivid

and it works great. Thanks to all developers for this great piece of work! Very well done,

Uranicus

tags: removed: lt-blocker
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package ofono - 1.17.bzr6910+16.04.20160115.3-0ubuntu1

---------------
ofono (1.17.bzr6910+16.04.20160115.3-0ubuntu1) xenial; urgency=medium

  [ Simon Fels ]
  [ Simon Fels]

  * voicecall: acquire wakelock when starting a HFP initated voicecall
    (LP: #1533716)
  * plugins: add android wakelock implementation
  * src: add wakelock abstraction

  [ CI Train Bot ]
  * No-change rebuild.

 -- Tony Espy <email address hidden> Fri, 15 Jan 2016 17:37:10 +0000

Changed in ofono (Ubuntu):
status: Fix Committed → Fix Released
Changed in canonical-devices-system-image:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.