Received-SPF: pass (google.com: best guess record for domain of linux-bluetooth-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Date:   Thu, 11 Jul 2019 20:42:52 +0000
From:   Matias Karhumaa <matias.karhumaa@gmail.com>
To:     Axelle <aafortinet@gmail.com>
Cc:     linux-bluetooth@vger.kernel.org
Subject: Re: SMP: Pairing failed with unspecified reason (0x08)
Message-ID: <20190711204252.GA2759@ubuntu-18-04-beta2>
References: <CANKzOHBCQ_ApbXXXNxjeRkrTwefxivgsVusqPxLaHkio3QitLA@mail.gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <CANKzOHBCQ_ApbXXXNxjeRkrTwefxivgsVusqPxLaHkio3QitLA@mail.gmail.com>
User-Agent: Mutt/1.9.4 (2018-02-28)
Sender: linux-bluetooth-owner@vger.kernel.org
Precedence: bulk

Hi Axelle,

On Thu, Jul 11, 2019 at 02:47:31PM +0200, Axelle wrote:
> I am trying to pair with a BLE device from a RPI device. The first few
> packets seem fine (Pairing Request, Pairing Response, LE Start
> Encryption, Signing Information...) but in the end I get a "Pairing
> Failed" SMP packet, with reason "Unspecified reason"  :(
> 
> Any explanation what could be the ... reason ;) and how to solve this please?
> 
> Thanks!

What kernel version you are running on RPI? How do you initiate pairing? 
There seems to be something weird going on in this btmon trace.

> 
> PS. This is the btmon log:
> 
> < HCI Command: Reset (0x03|0x0003) plen 0
>                          [hci0] 298.154979
> > HCI Event: Command Complete (0x0e) plen 4                                                     [hci0] 298.157882
>       Reset (0x03|0x0003) ncmd 1
>         Status: Success (0x00)
> < HCI Command: Set Event Filter (0x03|0x0005) plen 1
>                          [hci0] 298.171262
>         Type: Clear All Filters (0x00)
> > HCI Event: Command Complete (0x0e) plen 4                                                     [hci0] 298.171657
>       Set Event Filter (0x03|0x0005) ncmd 1
>         Status: Success (0x00)
> < HCI Command: Write Connection Accept Timeout (0x03|0x0016) plen 2
>                          [hci0] 298.185592
>         Timeout: 20000.000 msec (0x7d00)
> > HCI Event: Command Complete (0x0e) plen 4                                                     [hci0] 298.186005
>       Write Connection Accept Timeout (0x03|0x0016) ncmd 1
>         Status: Success (0x00)
> < HCI Command: Set Event Mask (0x03|0x0001) plen 8
>                          [hci0] 298.198904
>         Mask: 0x3dbff807fffbffff
>           Inquiry Complete
>           Inquiry Result
>           Connection Complete
>           Connection Request
>           Disconnection Complete
>           Authentication Complete
>           Remote Name Request Complete
>           Encryption Change
>           Change Connection Link Key Complete
>           Master Link Key Complete
>           Read Remote Supported Features Complete
>           Read Remote Version Information Complete
>           QoS Setup Complete
>           Command Complete
>           Command Status
>           Hardware Error
>           Flush Occurred
>           Role Change
>           Mode Change
>           Return Link Keys
>           PIN Code Request
>           Link Key Request
>           Link Key Notification
>           Loopback Command
>           Data Buffer Overflow
>           Max Slots Change
>           Read Clock Offset Complete
>           Connection Packet Type Changed
>           QoS Violation
>           Page Scan Mode Change
>           Page Scan Repetition Mode Change
>           Flow Specification Complete
>           Inquiry Result with RSSI
>           Read Remote Extended Features Complete
>           Synchronous Connection Complete
>           Synchronous Connection Changed
>           Sniff Subrating
>           Extended Inquiry Result
>           Encryption Key Refresh Complete
>           IO Capability Request
>           IO Capability Request Reply
>           User Confirmation Request
>           User Passkey Request
>           Remote OOB Data Request
>           Simple Pairing Complete
>           Link Supervision Timeout Changed
>           Enhanced Flush Complete
>           User Passkey Notification
>           Keypress Notification
>           Remote Host Supported Features Notification
>           LE Meta
> > HCI Event: Command Complete (0x0e) plen 4                                                     [hci0] 298.199255
>       Set Event Mask (0x03|0x0001) ncmd 1
>         Status: Success (0x00)
> < HCI Command: Write LE Host Supported (0x03|0x006d) plen 2
>                          [hci0] 298.214150
>         Supported: 0x01
>         Simultaneous: 0x01
> > HCI Event: Command Complete (0x0e) plen 4                                                     [hci0] 298.214499
>       Write LE Host Supported (0x03|0x006d) ncmd 1
>         Status: Success (0x00)
> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
>                          [hci0] 302.516667
>         Scan interval: 60.000 msec (0x0060)
>         Scan window: 30.000 msec (0x0030)
>         Filter policy: White list is not used (0x00)
>         Peer address type: Random (0x01)
>         Peer address: D2:A7:4C:76:F3:E0 (Static)
>         Own address type: Public (0x00)
>         Min connection interval: 50.00 msec (0x0028)
>         Max connection interval: 70.00 msec (0x0038)
>         Connection latency: 0x0000
>         Supervision timeout: 420 msec (0x002a)
>         Min connection length: 0.000 msec (0x0000)
>         Max connection length: 0.000 msec (0x0000)
> > HCI Event: Command Status (0x0f) plen 4                                                       [hci0] 302.517237
>       LE Create Connection (0x08|0x000d) ncmd 1
>         Status: Success (0x00)
> > HCI Event: LE Meta Event (0x3e) plen 19                                                       [hci0] 302.658079
>       LE Connection Complete (0x01)
>         Status: Success (0x00)
>         Handle: 64
>         Role: Master (0x00)
>         Peer address type: Random (0x01)
>         Peer address: D2:A7:4C:76:F3:E0 (Static)
>         Connection interval: 67.50 msec (0x0036)
>         Connection latency: 0.00 msec (0x0000)
>         Supervision timeout: 420 msec (0x002a)
>         Master clock accuracy: 0x00
> > ACL Data RX: Handle 64 flags 0x02 dlen 16                                                     [hci0] 307.789579
>       LE L2CAP: Connection Parameter Update Request (0x12) ident 2 len 8
>         Min interval: 6
>         Max interval: 12
>         Slave latency: 0
>         Timeout multiplier: 400
> < HCI Command: LE Connection Update (0x08|0x0013) plen 14
>                          [hci0] 307.813788
>         Handle: 64
>         Min connection interval: 7.50 msec (0x0006)
>         Max connection interval: 15.00 msec (0x000c)
>         Connection latency: 0x0000
>         Supervision timeout: 4000 msec (0x0190)
>         Min connection length: 0.000 msec (0x0000)
>         Max connection length: 0.000 msec (0x0000)
> > HCI Event: Command Status (0x0f) plen 4                                                       [hci0] 307.814226
>       LE Connection Update (0x08|0x0013) ncmd 1
>         Status: Success (0x00)
> < ACL Data TX: Handle 64 flags 0x00 dlen 10
>                          [hci0] 307.837601
>       LE L2CAP: Connection Parameter Update Response (0x13) ident 0 len 2
>         Result: Connection Parameters accepted (0x0000)
> > HCI Event: Number of Completed Packets (0x13) plen 5                                          [hci0] 308.157176
>         Num handles: 1
>         Handle: 64
>         Count: 1
> > HCI Event: LE Meta Event (0x3e) plen 10                                                       [hci0] 308.272198
>       LE Connection Update Complete (0x03)
>         Status: Success (0x00)
>         Handle: 64
>         Connection interval: 15.00 msec (0x000c)
>         Connection latency: 0.00 msec (0x0000)
>         Supervision timeout: 4000 msec (0x0190)
> < ACL Data TX: Handle 64 flags 0x00 dlen 11
>                          [hci0] 315.133782
>       SMP: Pairing Request (0x01) len 6
>         IO capability: KeyboardOnly (0x02)
>         OOB data: Authentication data not present (0x00)
>         Authentication requirement: Bonding, MITM, Legacy, No Keypresses (0x05)
>         Max encryption key size: 16
>         Initiator key distribution: EncKey Sign (0x05)
>         Responder key distribution: EncKey Sign (0x05)
> > ACL Data RX: Handle 64 flags 0x02 dlen 11                                                     [hci0] 315.157207
>       SMP: Pairing Response (0x02) len 6
>         IO capability: NoInputNoOutput (0x03)
>         OOB data: Authentication data not present (0x00)
>         Authentication requirement: Bonding, No MITM, Legacy, No
> Keypresses (0x01)
>         Max encryption key size: 16
>         Initiator key distribution: Sign (0x04)
>         Responder key distribution: EncKey (0x01)
> < HCI Command: Read BD ADDR (0x04|0x0009) plen 0
>                          [hci0] 315.165422
> > HCI Event: Command Complete (0x0e) plen 10                                                    [hci0] 315.165792
>       Read BD ADDR (0x04|0x0009) ncmd 1
>         Status: Success (0x00)
>         Address: B8:27:EB:15:50:70 (Raspberry Pi Foundation)
> < ACL Data TX: Handle 64 flags 0x00 dlen 21
>                          [hci0] 315.183781
>       SMP: Pairing Confirm (0x03) len 16
>         Confim value: 12e170d20c0bb8beb6d7c59bb006acd0
> > HCI Event: Number of Completed Packets (0x13) plen 5                                          [hci0] 315.187419
>         Num handles: 1
>         Handle: 64
>         Count: 2
> > ACL Data RX: Handle 64 flags 0x02 dlen 21                                                     [hci0] 315.202330
>       SMP: Pairing Confirm (0x03) len 16
>         Confim value: 6e0be0cc5a8f08ffc98a88c25167aa2f
> < ACL Data TX: Handle 64 flags 0x00 dlen 21
>                          [hci0] 315.219695
>       SMP: Pairing Random (0x04) len 16
>         Random value: 25498f1cc873d7450460df3b5ce2ab7e
> > ACL Data RX: Handle 64 flags 0x02 dlen 21                                                     [hci0] 315.247316
>       SMP: Pairing Random (0x04) len 16
>         Random value: 9e7769acf6f4c19706f9abde25d4749f
> < HCI Command: LE Start Encryption (0x08|0x0019) plen 28
>                          [hci0] 315.256836
>         Handle: 64
>         Random number: 0x0000000000000000
>         Encrypted diversifier: 0x0000
>         Long term key: 7689a6b5371537b24f2c7c7805688df6
> > HCI Event: Command Status (0x0f) plen 4                                                       [hci0] 315.257310
>       LE Start Encryption (0x08|0x0019) ncmd 1
>         Status: Success (0x00)
> > HCI Event: Encryption Change (0x08) plen 4                                                    [hci0] 315.337302
>         Status: Success (0x00)
>         Handle: 64
>         Encryption: Enabled with AES-CCM (0x01)
> > ACL Data RX: Handle 64 flags 0x02 dlen 21                                                     [hci0] 315.367776
>       SMP: Encryption Information (0x06) len 16
>         Long term key: b22ef80c481a8b4929e7159e0c2b0ba3
> > ACL Data RX: Handle 64 flags 0x02 dlen 15                                                     [hci0] 315.397264
>       SMP: Master Identification (0x07) len 10
>         EDIV: 0x02ee
>         Rand: 0x0720e828075f93eb
> > HCI Event: Number of Completed Packets (0x13) plen 5                                          [hci0] 315.407288
>         Num handles: 1
>         Handle: 64
>         Count: 1
> < ACL Data TX: Handle 64 flags 0x00 dlen 21
>                          [hci0] 315.416056
>       SMP: Encryption Information (0x06) len 16
>         Long term key: ffeeddccbbaa99887766554433221100
> < ACL Data TX: Handle 64 flags 0x00 dlen 15
>                          [hci0] 315.425880
>       SMP: Master Identification (0x07) len 10
>         EDIV: 0x000c
>         Rand: 0x8877665544332211

This looks weird here: to my understanding your RPI should not send
Encryption Information and Master Identification at all because only 
Sign bit is set in Pairing Response's Initiator key distribution flags.

It is possible that the other device does not like that and sends then
Pairing Failed.

Also Long Term Key and Rand values are somewhat suspicious and not
random as they should.

> < ACL Data TX: Handle 64 flags 0x00 dlen 21
>                          [hci0] 315.433926
>       SMP: Signing Information (0x0a) len 16
>         Signature key: ffeeddccbbaa99887766554433221100
> > ACL Data RX: Handle 64 flags 0x02 dlen 6                                                      [hci0] 315.442266
>       SMP: Pairing Failed (0x05) len 1
>         Reason: Unspecified reason (0x08)
> > HCI Event: Number of Completed Packets (0x13) plen 5                                          [hci0] 315.442543
>         Num handles: 1
>         Handle: 64
>         Count: 2
> > HCI Event: Number of Completed Packets (0x13) plen 5                                          [hci0] 315.532771
>         Num handles: 1
>         Handle: 64
>         Count: 1
> > HCI Event: Disconnect Complete (0x05) plen 4                                                  [hci0] 315.532868
>         Status: Success (0x00)
>         Handle: 64
>         Reason: Remote User Terminated Connection (0x13)

Best regards,
Matias