Bug 87226 - PulseAudio is interrupted for 380 milliseconds exactly every 20 minutes
Summary: PulseAudio is interrupted for 380 milliseconds exactly every 20 minutes
Status: RESOLVED INVALID
Alias: None
Product: PulseAudio
Classification: Unclassified
Component: modules (show other bugs)
Version: unspecified
Hardware: x86-64 (AMD64) Linux (All)
: medium normal
Assignee: pulseaudio-bugs
QA Contact: pulseaudio-bugs
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-12-11 07:37 UTC by Bert Aerts
Modified: 2014-12-17 14:48 UTC (History)
2 users (show)

See Also:
i915 platform:
i915 features:

Attachments

Description Bert Aerts 2014-12-11 07:37:51 UTC 
I have Mageia 4 x86_64 with all updates installed, so kernel 3.14.24.
On a Dell Inspiron 7720 17R SE laptop.

Both with speakers as with Logitech H800 wireless headphones via Bluetooth, I have an interruption of sound during 380 milliseconds exactly every 20 minutes.

This is proven by journalctl:

Dec 02 21:12:03 Dell7720Mageia4 pulseaudio[2969]: [bluetooth] module-bluez5-device.c: Skipping 387514 us (= 68356 bytes) in audio stream
Dec 02 21:32:04 Dell7720Mageia4 pulseaudio[2969]: [bluetooth] module-bluez5-device.c: Skipping 387286 us (= 68316 bytes) in audio stream

Dec 03 21:08:58 Dell7720Mageia4 pulseaudio[2791]: [bluetooth] module-bluez5-device.c: Skipping 386450 us (= 68168 bytes) in audio stream
Dec 03 21:28:58 Dell7720Mageia4 pulseaudio[2791]: [bluetooth] module-bluez5-device.c: Skipping 391516 us (= 69060 bytes) in audio stream

How can I debug this further to find a root-cause?

I did the following, at 19 minutes 50 seconds I ran:
top -bd .1 -n 150 > top_log_3.txt
grep -A 2 COMMAND top_log_3.txt > top_log_3_grep.txt

This resulted in just at the moment of sound interrupt (2 experiments with same result):

      PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
      601 root     -51   0     0    0    0 S    9  0.0   0:03.39 irq/46-iwlwifi
     2850 bert      20   0 3333m 138m  43m S    9  1.8   0:51.75 plasma-desktop

      PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
      607 root     -51   0     0    0    0 S    9  0.0   0:03.97 irq/46-iwlwifi
      837 root       0 -20     0    0    0 S    9  0.0   0:04.69 kworker/u17:2

But what can I conlude from this?
Comment 1 Bert Aerts 2014-12-14 12:13:49 UTC 
The second part is not relevant.
I have no exact correlation between sound interruption and occurance of irq/46-iwlwifi as there is no time-stamp available in top.
When there is no sound interrupt, irq/46-iwlwifi also reaches the top in the command top.

Question remains: how can I find the root-cause of the 380 millisecond interrupt in sound on bluetooth headphones that happens every 20 minutes?
Comment 2 Tanu Kaskinen 2014-12-15 08:58:09 UTC 
The fact that the iwlwifi irq doesn't always cause audio interruptions doesn't mean that it never causes them. Could you try unloading the iwlwifi module?
Comment 3 Bert Aerts 2014-12-15 16:08:38 UTC 
Tried to unload iwlwifi and succeeded in it. 
Bluetooth is handled by another module, as it kept on working.

[root@Dell7720Mageia4 bert]# rmmod iwlwifi
rmmod: ERROR: Module iwlwifi is in use by: iwldvm
[root@Dell7720Mageia4 bert]# rmmod iwldvm
[root@Dell7720Mageia4 bert]# rmmod iwlwifi

But still interrupt in sound via Bluetooth headphones as shown here:

[root@Dell7720Mageia4 bert]# journalctl --lines=20
-- Logs begin at Fri 2014-02-21 19:17:02 CET, end at Mon 2014-12-15 12:39:03 CET. --
Dec 15 12:36:54 Dell7720Mageia4 chronyd[966]: Can't synchronise: no reachable sources
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Chip: i8k-virtual-0
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Adapter: Virtual device
Dec 15 12:39:03 Dell7720Mageia4 pulseaudio[5259]: [bluetooth] module-bluez5-device.c: Skipping 400501 us (= 70648 bytes) in audio stream
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Right Fan: 0 RPM
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: CPU: 68.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: temp2: 37.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: temp3: 51.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: temp4: 55.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Chip: acpitz-virtual-0
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Adapter: Virtual device
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: temp1: 70.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: temp2: 70.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Chip: coretemp-isa-0000
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Adapter: ISA adapter
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Physical id 0: 69.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Core 0: 62.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Core 1: 60.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Core 2: 61.0 C
Dec 15 12:39:03 Dell7720Mageia4 sensord[1135]: Core 3: 68.0 C

But exactly at the moment of interrupt in sound, sensord was active.
So what is the priority of sensord?

[root@Dell7720Mageia4 bert]# ps -ef | grep sensord
UID        PID  PPID  C STIME TTY          TIME CMD
root      1135     1  0 12:19 ?        00:00:01 /usr/sbin/sensord -i 1m -l 20m -f daemon

What do we see: logging every 20 minutes... twenty minutes... the sound interrupt interval !!!

So I disabled sensord in Mageia Control Center / System / Manage System Services

And the 20 minutes interval passed without sound interruption !!!
Comment 4 Bert Aerts 2014-12-17 14:45:55 UTC 
Marked as FIXED and INVALID.

As it is not a PulseAudio bug but an i8k bug.
After unloading kernel module i8k, the command sensors works OK.
No interrupt in sound anymore.
i8k is intended for accessing data from the SMM BIOS and the DMI table on Dell laptops, but is not up to date for my Dell Inspiron 17R SE 7720.
Comment 5 Tanu Kaskinen 2014-12-17 14:48:06 UTC 
I'm happy to hear you got the problem resolved!

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.