On Thursday 02 of January 2014 23:55:25 Jakub Jechanowski wrote:
> After pairing and connecting (bluetoothctl or bluetooth-wizard) mouse
> works ok. But when I restart bluetoothd (or whole OS) mouse no longer
> works. After touching the mouse, in bluetoothd log I get:
>
> bluetoothd[6418]: src/adapter.c:connected_callback() hci0 device
> 00:07:61:68:55:27 connected eir_len 5
> bluetoothd[6418]: src/device.c:device_create() dst 00:07:61:68:55:27
> bluetoothd[6418]: src/device.c:device_new() address 00:07:61:68:55:27
> bluetoothd[6418]: src/device.c:device_new() Creating device
> /org/bluez/hci0/dev_00_07_61_68_55_27
> bluetoothd[6418]: src/device.c:btd_device_set_temporary() temporary 1
> bluetoothd[6418]: src/adapter.c:adapter_connect_list_remove() device
> /org/bluez/hci0/dev_00_07_61_68_55_27 is not on the list, ignoring
> bluetoothd[6418]: src/device.c:device_set_class()
> /org/bluez/hci0/dev_00_07_61_68_55_27 0x002580
> bluetoothd[6418]: profiles/input/server.c:connect_event_cb() Incoming
> connection from 00:07:61:68:55:27 on PSM 17
> bluetoothd[6418]: profiles/input/device.c:input_device_set_channel()
> idev (nil) psm 17
> bluetoothd[6418]: Refusing input device connect: No such file or directory (2)
> bluetoothd[6418]: profiles/input/server.c:confirm_event_cb()
> bluetoothd[6418]: Refusing connection from 00:07:61:68:55:27: unknown device
> <<<few seconds of pause>>>
> bluetoothd[6418]: src/adapter.c:dev_disconnected() Device
> 00:07:61:68:55:27 disconnected, reason 2
> bluetoothd[6418]: src/adapter.c:adapter_remove_connection()
> bluetoothd[6418]: src/adapter.c:adapter_remove_connection() Removing
> temporary device /org/bluez/hci0/dev_00_07_61_68_55_27
> bluetoothd[6418]: src/device.c:device_remove() Removing device
> /org/bluez/hci0/dev_00_07_61_68_55_27
> bluetoothd[6418]: src/device.c:btd_device_unref() Freeing device
> /org/bluez/hci0/dev_00_07_61_68_55_27
> bluetoothd[6418]: src/device.c:device_free() 0x24a65e0
> bluetoothd[6418]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr
> 00:07:61:68:55:27 type 0 status 0xe
> bluetoothd[6418]: src/adapter.c:resume_discovery()
>
> ------------------------------------
>
> Log from btmon after touching mouse:
>
> > HCI Event: Connect Request (0x04) plen 10 [hci0] 9.133728
> Address: 00:07:61:68:55:27 (Logitech Europe SA)
> Class: 0x002580
> Major class: Peripheral (mouse, joystick, keyboards)
> Minor class: 0x20
> Limited Discoverable Mode
> Link type: ACL (0x01)
> < HCI Command: Accept Connection Request (0x01|0x0009) plen 7 [hci0] 9.133770
> Address: 00:07:61:68:55:27 (Logitech Europe SA)
> Role: Master (0x00)
> > HCI Event: Command Status (0x0f) plen 4 [hci0] 9.136727
> Accept Connection Request (0x01|0x0009) ncmd 1
> Status: Success (0x00)
> > HCI Event: Role Change (0x12) plen 8 [hci0] 9.294753
> Status: Success (0x00)
> Address: 00:07:61:68:55:27 (Logitech Europe SA)
> Role: Master (0x00)
> > HCI Event: Connect Complete (0x03) plen 11 [hci0] 9.444736
> Status: Success (0x00)
> Handle: 11
> Address: 00:07:61:68:55:27 (Logitech Europe SA)
> Link type: ACL (0x01)
> Encryption: Disabled (0x00)
> < HCI Command: Read Remote Supported Fe.. (0x01|0x001b) plen 2 [hci0] 9.444839
> Handle: 11
> > HCI Event: Command Status (0x0f) plen 4 [hci0] 9.446731
> Read Remote Supported Features (0x01|0x001b) ncmd 1
> Status: Success (0x00)
> > HCI Event: Read Remote Supported Features (0x0b) plen 11 [hci0] 9.448739
> Status: Success (0x00)
> Handle: 11
> Features: 0xfc 0xff 0x0f 0x00 0x08 0x08 0x00 0x00
> Encryption
> Slot offset
> Timing accuracy
> Role switch
> Hold mode
> Sniff mode
> Park state
> Power control requests
> Channel quality driven data rate (CQDDR)
> SCO link
> HV2 packets
> HV3 packets
> u-law log synchronous data
> A-law log synchronous data
> CVSD synchronous data
> Paging parameter negotiation
> Power control
> Transparent synchronous data
> AFH capable slave
> AFH capable master
> < HCI Command: Remote Name Request (0x01|0x0019) plen 10 [hci0] 9.448793
> Address: 00:07:61:68:55:27 (Logitech Europe SA)
> Page scan repetition mode: R2 (0x02)
> Page scan mode: Mandatory (0x00)
> Clock offset: 0x0000
> > HCI Event: Command Status (0x0f) plen 4 [hci0] 9.449737
> Remote Name Request (0x01|0x0019) ncmd 1
> Status: Success (0x00)
> > ACL Data RX: Handle 11 flags 0x02 dlen 12 [hci0] 9.477736
> L2CAP: Connection Request (0x02) ident 1 len 4
> PSM: 17 (0x0011)
> Source CID: 64
> < ACL Data TX: Handle 11 flags 0x02 dlen 16 [hci0] 9.477798
> L2CAP: Connection Response (0x03) ident 1 len 8
> Destination CID: 64
> Source CID: 64
> Result: Connection pending (0x0001)
> Status: No further information available (0x0000)
> < ACL Data TX: Handle 11 flags 0x02 dlen 10 [hci0] 9.477805
> L2CAP: Information Request (0x0a) ident 1 len 2
> Type: Extended features supported (0x0002)
> @ Device Connected: 00:07:61:68:55:27 (0) flags 0x0000
> 04 0d 80 25 00 ...%.
> > HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 9.485716
> Num handles: 1
> Handle: 11
> Count: 2
> > ACL Data RX: Handle 11 flags 0x02 dlen 16 [hci0] 9.501737
> L2CAP: Information Response (0x0b) ident 1 len 8
> Type: Extended features supported (0x0002)
> Result: Success (0x0000)
> Features: 0x00000000
> < ACL Data TX: Handle 11 flags 0x02 dlen 16 [hci0] 9.502107
> L2CAP: Connection Response (0x03) ident 1 len 8
> Destination CID: 64
> Source CID: 64
> Result: Connection successful (0x0000)
> Status: No further information available (0x0000)
> < ACL Data TX: Handle 11 flags 0x02 dlen 12 [hci0] 9.502113
> L2CAP: Configure Request (0x04) ident 2 len 4
> Destination CID: 64
> Flags: 0x0000
> > HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 9.507719
> Num handles: 1
> Handle: 11
> Count: 2
> > HCI Event: Remote Name Req Complete (0x07) plen 255 [hci0] 9.548727
> Status: Success (0x00)
> Address: 00:07:61:68:55:27 (Logitech Europe SA)
> Name: Bluetooth Travel Mouse
> > ACL Data RX: Handle 11 flags 0x02 dlen 17 [hci0] 9.555740
> > ACL Data RX: Handle 11 flags 0x01 dlen 17 [hci0] 9.556723
> > HCI Event: QoS Setup Complete (0x0d) plen 21 [hci0] 9.557718
> Status: Success (0x00)
> Handle: 11
> Flags: 0x00
> Service type: Best Effort (0x01)
> Token rate: 1511
> Peak bandwidth: 0
> Latency: 11250
> Delay variation: -1
> > ACL Data RX: Handle 11 flags 0x01 dlen 6 [hci0] 9.557726
> L2CAP: Configure Request (0x04) ident 2 len 32
> Destination CID: 64
> Flags: 0x0000
> Option: Maximum Transmission Unit (0x01)
> MTU: 48
> Option: Quality of Service (0x03)
> Flags: 0x00
> Service type: Best Effort (0x01)
> Token rate: 0x00000000
> Token bucket size: 0x00000000
> Peak bandwidth: 0x00000000
> Latency: 0x00002bf2
> Delay variation: 0xffffffff
> < ACL Data TX: Handle 11 flags 0x02 dlen 18 [hci0] 9.557754
> L2CAP: Configure Response (0x05) ident 2 len 10
> Source CID: 64
> Flags: 0x0000
> Result: Success (0x0000)
> Option: Maximum Transmission Unit (0x01)
> MTU: 48
> > ACL Data RX: Handle 11 flags 0x02 dlen 14 [hci0] 9.570733
> L2CAP: Configure Response (0x05) ident 2 len 6
> Source CID: 64
> Flags: 0x0000
> Result: Success (0x0000)
> < ACL Data TX: Handle 11 flags 0x02 dlen 5 [hci0] 9.571076
> Channel: 64 len 1 [PSM 17 mode 0] {chan 0}
> 15 .
> < ACL Data TX: Handle 11 flags 0x02 dlen 12 [hci0] 9.571284
> L2CAP: Disconnection Request (0x06) ident 3 len 4
> Destination CID: 64
> Source CID: 64
> > HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 9.573737
> Num handles: 1
> Handle: 11
> Count: 2
> > ACL Data RX: Handle 11 flags 0x02 dlen 12 [hci0] 9.610754
> L2CAP: Connection Request (0x02) ident 3 len 4
> PSM: 19 (0x0013)
> Source CID: 65
> < ACL Data TX: Handle 11 flags 0x02 dlen 16 [hci0] 9.610846
> L2CAP: Connection Response (0x03) ident 3 len 8
> Destination CID: 65
> Source CID: 65
> Result: Connection pending (0x0001)
> Status: Authorization pending (0x0002)
> < ACL Data TX: Handle 11 flags 0x02 dlen 16 [hci0] 9.612931
> L2CAP: Connection Response (0x03) ident 3 len 8
> Destination CID: 65
> Source CID: 65
> Result: Connection refused - security block (0x0003)
> Status: No further information available (0x0000)
> > HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 9.613738
> Num handles: 1
> Handle: 11
> Count: 2
> > ACL Data RX: Handle 11 flags 0x02 dlen 12 [hci0] 9.640735
> L2CAP: Disconnection Response (0x07) ident 3 len 4
> Destination CID: 64
> Source CID: 64
> > HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 9.854750
> Num handles: 1
> Handle: 11
> Count: 1
> < HCI Command: Disconnect (0x01|0x0006) plen 3 [hci0] 13.650261
> Handle: 11
> Reason: Remote User Terminated Connection (0x13)
> > HCI Event: Command Status (0x0f) plen 4 [hci0] 13.652743
> Disconnect (0x01|0x0006) ncmd 1
> Status: Success (0x00)
> > HCI Event: Disconnect Complete (0x05) plen 4 [hci0] 13.705753
> Status: Success (0x00)
> Handle: 11
> Reason: Connection Terminated By Local Host (0x16)
> @ Device Disconnected: 00:07:61:68:55:27 (0) reason 2
>
>
> ------------------------------------
>
> I also noticed, that after bluetoothd restart, lists of devices and
> paired-devices are empty:
This looks like issues with storage. Could you check if bluetoothd is able to
access storage directory (/var/lib/bluetooth) ?
> [root@pavilion 00:24:7E:F4:D7:EC]# bluetoothctl
> [NEW] Controller 00:24:7E:F4:D7:EC pavilion [default]
> [NEW] Device 00:07:61:68:55:27 Bluetooth Travel Mouse
> [bluetooth]# devices
> Device 00:07:61:68:55:27 Bluetooth Travel Mouse
> [bluetooth]# paired-devices
> Device 00:07:61:68:55:27 Bluetooth Travel Mouse
> <<< restart of bluetoothd >>>
> [bluetooth]# devices
> [bluetooth]# paired-devices
> [bluetooth]# exit
> [DEL] Controller 00:24:7E:F4:D7:EC pavilion [default]
>
>
> Bluez 5.13, Arch Linux
>
> Mouse worked without problems on Bluez 4.x
>
> It seems to be similar to "Missing AuthorizeService callback?" topic
> from 2013-12-10.
>
> Cheers, Kuba
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in
> the body of a message to majordomo@xxxxxxxxxxxxxxx
> More majordomo info at http://vger.kernel.org/majordomo-info.html
--
Best regards,
Szymon Janc
--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
