Hi,

I'm experimenting sometime trouble with bluetoothd...

As I'm using a bluetooth mouse, I need it most of the time !

I'm using hibernation feature to turn my computer off.

After restarting, the bluetooth doesn't work anymore unless I restart
bluetoothd manually ! It does not happen every time, but 1-2 time for 3 restarts...

There are no significant log as you can see or I missed something :
[17123.943571] wlan0: deauthenticating from 00:21:29:ec:72:b1 by local choice
(reason=3)
[17123.968150] cfg80211: Calling CRDA to update world regulatory domain
[17127.316422] ADDRCONF(NETDEV_UP): wlan0: link is not ready
[17137.486305] sky2 0000:04:00.0: eth0: disabling interface
[17138.762071] EXT4-fs (sda3): re-mounted. Opts: errors=remount-ro,commit=0
[17139.098872] EXT4-fs (sda6): re-mounted. Opts: acl,commit=0
[17139.260058] EXT4-fs (sda5): re-mounted. Opts: commit=0
[17140.974547] PM: Marking nosave pages: 000000000009e000 - 0000000000100000
[17140.974551] PM: Marking nosave pages: 00000000cee7a000 - 0000000100000000
[17140.975567] PM: Basic memory bitmaps created
[17140.975569] PM: Syncing filesystems ... done.
[17141.091426] Freezing user space processes ... (elapsed 0.01 seconds) done.
[17141.108069] Freezing remaining freezable tasks ... (elapsed 0.01 seconds)
done.
[17141.124188] PM: Preallocating image memory... done (allocated 1378208 pages)
[17141.817556] PM: Allocated 5512832 kbytes in 0.69 seconds (7989.61 MB/s)
[17141.817558] Suspending console(s) (use no_console_suspend to debug)
[17141.818222] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[17141.818577] sdhci-pci 0000:03:00.4: PCI INT C disabled
[17141.818654] sdhci-pci 0000:03:00.0: PCI INT A disabled
[17141.820340] pci 0000:00:1f.6: PCI INT C disabled
[17141.822975] ACPI handle has no context!
[17141.922753] HDA Intel 0000:00:1b.0: PCI INT A disabled
[17142.150276] HDA Intel 0000:01:00.1: PCI INT A disabled
[17142.150336] ACPI handle has no context!
[17142.166241] PM: freeze of devices complete after 349.078 msecs
[17142.166773] PM: late freeze of devices complete after 0.530 msecs
[17142.166913] ACPI: Preparing to enter system sleep state S4
[17142.167366] PM: Saving platform NVS memory
[17142.168099] Disabling non-boot CPUs ...
[17142.270070] CPU 1 is now offline
[17142.425774] CPU 2 is now offline
[17142.561540] CPU 3 is now offline
[17142.562124] Extended CMOS year: 2000
[17142.562233] PM: Creating hibernation image:
[17142.662767] PM: Need to copy 605529 pages
[17142.662769] PM: Normal pages needed: 605529 + 1024, available pages: 1486880
[17142.562266] PM: Restoring platform NVS memory
[17142.562784] CPU0: Thermal monitoring handled by SMI
[17142.562842] Extended CMOS year: 2000
[17142.562885] Enabling non-boot CPUs ...
[17142.563054] Booting Node 0 Processor 1 APIC 0x4
[17142.563055] smpboot cpu 1: start_ip = 99000
[17142.650127] CPU1: Thermal monitoring handled by SMI
[17142.670321] NMI watchdog enabled, takes one hw-pmu counter.
[17142.670625] CPU1 is up
[17142.670768] Booting Node 0 Processor 2 APIC 0x1
[17142.670770] smpboot cpu 2: start_ip = 99000
[17142.674068] Switched to NOHz mode on CPU #1
[17142.757941] CPU2: Thermal monitoring handled by SMI
[17142.778370] NMI watchdog enabled, takes one hw-pmu counter.
[17142.778746] CPU2 is up
[17142.778921] Booting Node 0 Processor 3 APIC 0x5
[17142.778923] smpboot cpu 3: start_ip = 99000
[17142.781884] Switched to NOHz mode on CPU #2
[17142.869753] CPU3: Thermal monitoring handled by SMI
[17142.893692] Switched to NOHz mode on CPU #3
[17142.898172] NMI watchdog enabled, takes one hw-pmu counter.
[17142.898542] CPU3 is up
[17142.900296] ACPI: Waking up from system sleep state S4
[17143.305595] HDA Intel 0000:00:1b.0: restoring config space at offset 0x1
(was 0x100006, writing 0x100002)
[17143.305969] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was
0x2b00403, writing 0x2b00407)
[17143.306057] pci 0000:00:1f.6: restoring config space at offset 0x1 (was
0x100006, writing 0x100002)
[17143.306087] nvidia 0000:01:00.0: restoring config space at offset 0xc (was
0xe3000000, writing 0x0)
[17143.306097] nvidia 0000:01:00.0: restoring config space at offset 0x3 (was
0x800010, writing 0x800000)
[17143.306140] HDA Intel 0000:01:00.1: restoring config space at offset 0x1
(was 0x100006, writing 0x100002)
[17143.320971] sdhci-pci 0000:03:00.0: BAR 0: set to [mem
0xe6603000-0xe66030ff] (PCI address [0xe6603000-0xe66030ff])
[17143.321027] sdhci-pci 0000:03:00.0: restoring config space at offset 0x1
(was 0x100002, writing 0x100006)
[17143.336940] firewire_ohci 0000:03:00.3: BAR 0: set to [mem
0xe6601000-0xe66017ff] (PCI address [0xe6601000-0xe66017ff])
[17143.352909] sdhci-pci 0000:03:00.4: BAR 0: set to [mem
0xe6600000-0xe66000ff] (PCI address [0xe6600000-0xe66000ff])
[17143.352965] sdhci-pci 0000:03:00.4: restoring config space at offset 0x1
(was 0x100002, writing 0x100006)
[17143.353194] PM: early restore of devices complete after 47.857 msecs
[17143.518944] ehci_hcd 0000:00:1a.0: setting latency timer to 64
[17143.518976] usb usb1: root hub lost power or was reset
[17143.522912] ehci_hcd 0000:00:1a.0: cache line size of 64 is not supported
[17143.522915] HDA Intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ
22
[17143.522930] HDA Intel 0000:00:1b.0: setting latency timer to 64
[17143.522933] ehci_hcd 0000:00:1d.0: setting latency timer to 64
[17143.522936] pci 0000:00:1e.0: setting latency timer to 64
[17143.522945] ahci 0000:00:1f.2: setting latency timer to 64
[17143.522953] pci 0000:00:1f.6: PCI INT C -> GSI 18 (level, low) -> IRQ 18
[17143.522956] usb usb2: root hub lost power or was reset
[17143.526849] ehci_hcd 0000:00:1d.0: cache line size of 64 is not supported
[17143.526875] sdhci-pci 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ
17
[17143.526942] HDA Intel 0000:00:1b.0: irq 43 for MSI/MSI-X
[17143.526968] sdhci-pci 0000:03:00.4: PCI INT C -> GSI 19 (level, low) -> IRQ
19
[17143.527055] HDA Intel 0000:01:00.1: PCI INT A -> GSI 16 (level, low) -> IRQ
16
[17143.527060] HDA Intel 0000:01:00.1: setting latency timer to 64
[17143.527199] sd 0:0:0:0: [sda] Starting disk
[17143.580632] firewire_ohci 0000:03:00.3: irq 44 for MSI/MSI-X
[17143.580740] firewire_core: skipped bus generations, destroying all nodes
[17143.844169] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[17143.844234] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[17143.845072] ata1.00: ACPI cmd f5/00:00:00:00:00:00 (SECURITY FREEZE LOCK)
filtered out
[17143.846494] ata1.00: ACPI cmd f5/00:00:00:00:00:00 (SECURITY FREEZE LOCK)
filtered out
[17143.846937] ata1.00: configured for UDMA/133
[17143.866185] ata2.00: configured for UDMA/100
[17143.872036] usb 1-1: reset high speed USB device number 2 using ehci_hcd
[17144.027752] sdhci-pci 0000:03:00.4: Will use DMA mode even though HW doesn't
fully claim to support it.
[17144.027765] sdhci-pci 0000:03:00.4: setting latency timer to 64
[17144.027811] sdhci-pci 0000:03:00.0: Will use DMA mode even though HW doesn't
fully claim to support it.
[17144.027822] sdhci-pci 0000:03:00.0: setting latency timer to 64
[17144.115608] usb 2-1: reset high speed USB device number 2 using ehci_hcd
[17144.319354] usb 1-1.6: reset full speed USB device number 4 using ehci_hcd
[17144.413348] btusb 1-1.6:1.0: no reset_resume for driver btusb?
[17144.413350] btusb 1-1.6:1.1: no reset_resume for driver btusb?
[17144.483066] usb 1-1.2: reset high speed USB device number 3 using ehci_hcd
[17144.730473] firewire_core: rediscovered device fw0
[17144.730996] PM: restore of devices complete after 1214.199 msecs
[17144.731238] PM: Image restored successfully.
[17144.731239] Restarting tasks ... done.
[17144.741550] PM: Basic memory bitmaps freed
[17144.741556] video LNXVIDEO:01: Restoring backlight state
[17145.644226] EXT4-fs (sda3): re-mounted. Opts: errors=remount-ro,commit=600
[17145.817782] EXT4-fs (sda6): re-mounted. Opts: acl,commit=600
[17145.964515] EXT4-fs (sda5): re-mounted. Opts: commit=600
[17146.189370] ADDRCONF(NETDEV_UP): wlan0: link is not ready
[17146.194226] sky2 0000:04:00.0: eth0: enabling interface
[17146.194947] ADDRCONF(NETDEV_UP): eth0: link is not ready
[17147.614557] EXT4-fs (sda3): re-mounted. Opts: errors=remount-ro,commit=600
[17147.911440] EXT4-fs (sda6): re-mounted. Opts: acl,commit=600
[17147.918845] EXT4-fs (sda5): re-mounted. Opts: commit=600
[17291.991000] sky2 0000:04:00.0: eth0: Link is up at 1000 Mbps, full duplex,
flow control rx
[17291.992330] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[17295.074992] EXT4-fs (sda3): re-mounted. Opts: errors=remount-ro,commit=0
[17295.154472] EXT4-fs (sda6): re-mounted. Opts: acl,commit=0
[17295.160058] EXT4-fs (sda5): re-mounted. Opts: commit=0
[17302.962403] eth0: no IPv6 routers present

I you need more information, I could try to make more tests...

Regards

Mourad

I'm seeing the same problem resuming from suspend only for me, the bluetooth
may work 1 out of 10 resumes.

The only way I can restore bluetooth after a suspend is to restart the
bluetooth daemon or unplug/replug the usb dongle.

Here is the output when I plug in the device:
[87025.252078] usb 6-1: new full speed USB device number 12 using uhci_hcd
[87025.314115] usb 6-1: New USB device found, idVendor=047d, idProduct=105e
[87025.314124] usb 6-1: New USB device strings: Mfr=1, Product=2,
SerialNumber=3
[87025.314132] usb 6-1: Product: BCM92045B3 ROM
[87025.314137] usb 6-1: Manufacturer: Broadcom Corp
[87025.314143] usb 6-1: SerialNumber: 00191566A46A

Here is a section from my /var/log/daemon.log when the bluetooth fails to work
post resume.
Sep  7 11:40:40 user-laptop acpid: client 1617[0:0] has disconnected
Sep  7 11:40:40 user-laptop bluetoothd[14430]: HCI dev 0 down
Sep  7 11:40:40 user-laptop bluetoothd[14430]: Adapter /org/bluez/14430/hci0
has been disabled
Sep  7 11:40:40 user-laptop bluetoothd[14430]: HCI dev 0 unregistered
Sep  7 11:40:40 user-laptop bluetoothd[14430]: Stopping hci0 event socket
Sep  7 11:40:40 user-laptop bluetoothd[14430]: Unregister path:
/org/bluez/14430/hci0
Sep  7 11:40:40 user-laptop bluetoothd[14430]: HCI dev 0 registered
Sep  7 11:40:40 user-laptop bluetoothd[14430]: Listening for HCI events on hci0
Sep  7 11:40:40 user-laptop bluetoothd[14430]: HCI dev 0 up
Sep  7 11:40:40 user-laptop acpid: client connected from 1617[0:0]
Sep  7 11:40:40 user-laptop acpid: 1 client rule loaded
Sep  7 11:40:44 user-laptop dhclient: receive_packet failed on wlan0: Network
is down
Sep  7 11:40:44 user-laptop dhclient: receive_packet failed on wlan0: Network
is down
Sep  7 11:40:48 user-laptop nmbd[1709]: [2011/09/07 11:40:48.152484,  0]
lib/interface.c:542(load_interfaces)
Sep  7 11:40:48 user-laptop nmbd[1709]:   WARNING: no network interfaces found

Here is working bluetooth post resume
Sep  7 22:56:34 user-laptop acpid: client 1617[0:0] has disconnected
Sep  7 22:56:34 user-laptop bluetoothd[14430]: HCI dev 0 down
Sep  7 22:56:34 user-laptop bluetoothd[14430]: Adapter /org/bluez/14430/hci0
has been disabled
Sep  7 22:56:34 user-laptop bluetoothd[14430]: HCI dev 0 unregistered
Sep  7 22:56:34 user-laptop bluetoothd[14430]: Stopping hci0 event socket
Sep  7 22:56:34 user-laptop bluetoothd[14430]: Unregister path:
/org/bluez/14430/hci0
Sep  7 22:56:34 user-laptop bluetoothd[14430]: HCI dev 0 registered
Sep  7 22:56:34 user-laptop bluetoothd[14430]: Listening for HCI events on hci0
Sep  7 22:56:34 user-laptop bluetoothd[14430]: HCI dev 0 up
Sep  7 22:56:34 user-laptop bluetoothd[14430]: input-headset driver probe
failed for device 5C:17:D3:EA:73:B6
Sep  7 22:56:34 user-laptop bluetoothd[14430]: Adapter /org/bluez/14430/hci0
has been enabled
Sep  7 22:56:34 user-laptop acpid: client connected from 1617[0:0]
Sep  7 22:56:34 user-laptop acpid: 1 client rule loaded
Sep  7 22:56:38 user-laptop dhclient: receive_packet failed on wlan0: Network
is down
Sep  7 22:56:38 user-laptop dhclient: DHCPREQUEST on wlan0 to 192.168.1.254
port 67
Sep  7 22:56:38 user-laptop dhclient: send_packet: Network is unreachable
Sep  7 22:56:38 user-laptop dhclient: send_packet: please consult README file
regarding broadcast address.
Sep  7 22:56:39 user-laptop dhclient: receive_packet failed on wlan0: Network
is down
Sep  7 22:56:42 user-laptop dhclient: DHCPREQUEST on wlan0 to 192.168.1.254
port 67
Sep  7 22:56:42 user-laptop dhclient: send_packet: Network is unreachable
Sep  7 22:56:42 user-laptop dhclient: send_packet: please consult README file
regarding broadcast address.
Sep  7 22:56:53 user-laptop dhclient: DHCPREQUEST on wlan0 to 192.168.1.254
port 67
Sep  7 22:56:55 user-laptop dhclient: DHCPACK from 192.168.1.254
Sep  7 22:56:55 user-laptop dhclient: bound to 192.168.1.65 -- renewal in 34710
seconds.

The line "Adapter /org/bluez/14430/hci0 has been enabled" seems to be the
indication that the bluetooth adapter will work post resume. Perhaps this is a
dbus issue?

I can do more testing if needed.

Hi!

I'm also affected by this bug. I never hibernate so I just can speak
about suspending. It happens very often but not everytime I resume. I
can provide more informations but ask me because I don't know what to
provide.

Thanks!

This is happening every single time I resume from suspend.  My laptop's
bluetooth chipset is running (since I have the bluetooth kernel module
and relevant firmware), but the daemon won't restart until I manually
invoke /etc/init.d/bluetooth restart as root or sudo.

Dear Maintainer,
Same situation.

When any powerreduce act (p.e. display shutoff) the Bluetooth goes off, as
WiFi, but on resume WiFi restarts normally, bluetooth no.
bluetoothctl reports no controller on list command.
blueman fails to start.
blueman-adapters 12.39.01 ERROR    Adapter:54 __init__  : No adapter(s) found

*** Reporter, please consider answering these questions, where appropriate ***

   * What led up to the situation?
   * What exactly did you do (or not do) that was effective (or
     ineffective)?
   * What was the outcome of this action?
   * What outcome did you expect instead?

*** End of the template - remove these template lines ***

During boot I have this message:
[    5.691087] Bluetooth: hci0: unexpected event for opcode 0xfc2f

When bluetooth end to work the only solution is to reboot. If during the
boot there is the error bluetooth works, if error doesn't appear the
bluetooth will not work and the possible solutions are:
- Enter in BIOS, disable all wifi chips, reboot, reboot entering bios,
enable wifi, reboot and bluetooth works until first power save.
- Reboot in Windows, make logon in windows, connect a bluetooth device
(in my case, the mouse), reboot in linux.

This is the dmesg of a boot with working bluetooth:
root@lenovo:/home/nicola# dmesg | grep Bluetooth
[    5.001610] Bluetooth: Core ver 2.22
[    5.001646] Bluetooth: HCI device and connection manager initialized
[    5.001650] Bluetooth: HCI socket layer initialized
[    5.001653] Bluetooth: L2CAP socket layer initialized
[    5.001658] Bluetooth: SCO socket layer initialized
[    5.248726] Bluetooth: hci0: Legacy ROM 2.5 revision 1.0 build 3 week
17 2014
[    5.249164] Bluetooth: hci0: Intel Bluetooth firmware file:
intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq
[    5.303813] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    5.303817] Bluetooth: BNEP filters: protocol multicast
[    5.303821] Bluetooth: BNEP socket layer initialized
[    5.691087] Bluetooth: hci0: unexpected event for opcode 0xfc2f
[    5.709161] Bluetooth: hci0: Intel BT fw patch 0x32 completed & activated
[    9.179064] Bluetooth: RFCOMM TTY layer initialized
[    9.179081] Bluetooth: RFCOMM socket layer initialized
[    9.179088] Bluetooth: RFCOMM ver 1.11


This is the dmesg of a boot with Bluetooth not working:

gen 14 15:37:59 lenovo kernel: Bluetooth: Core ver 2.22
gen 14 15:37:59 lenovo kernel: Bluetooth: HCI device and connection
manager initialized
gen 14 15:37:59 lenovo kernel: Bluetooth: HCI socket layer initialized
gen 14 15:37:59 lenovo kernel: Bluetooth: L2CAP socket layer initialized
gen 14 15:37:59 lenovo kernel: Bluetooth: SCO socket layer initialized
gen 14 15:38:00 lenovo kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
gen 14 15:38:00 lenovo kernel: Bluetooth: BNEP filters: protocol multicast
gen 14 15:38:00 lenovo kernel: Bluetooth: BNEP socket layer initialized
gen 14 15:38:02 lenovo kernel: Bluetooth: hci0: Reading Intel version
command failed (-110)
gen 14 15:38:02 lenovo kernel: Bluetooth: hci0: command tx timeout

------ Original Message ------
From: Nicola <brambil@gmail.com>
To: Debian Bug Tracking System <632960@bugs.debian.org>
Date: Fri, 14 Jan 2022 12:39:27 +0100
M-ID:
<164216036710.35866.5086530836768427074.reportbug@Lenovo.homenet.telecomitalia.it>
Subject: Bug#632960: bluetooth: Bluetoothd dies after restoring from
hibernate PM


P
Please consider the enviroment before printing.
Pensa all'ambiente prima di stampare.
----
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they are
addressed. If you have received this email in error please notify the
originator of the message. Any views expressed in this message are those
of the individual sender. This footer also confirms that this email
message has been scanned for the presence of computer viruses.