Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-0.6 required=3.0 tests=DKIM_SIGNED,DKIM_VALID, DKIM_VALID_AU,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_PASS autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 16BB1ECE561 for ; Tue, 25 Sep 2018 16:08:48 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 8956C20867 for ; Tue, 25 Sep 2018 16:08:47 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=pass (2048-bit key) header.d=gmail.com header.i=@gmail.com header.b="WI41b5WO" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 8956C20867 Authentication-Results: mail.kernel.org; dmarc=fail (p=none dis=none) header.from=gmail.com Authentication-Results: mail.kernel.org; spf=none smtp.mailfrom=linux-bluetooth-owner@vger.kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1729100AbeIYWQ4 (ORCPT ); Tue, 25 Sep 2018 18:16:56 -0400 Received: from mail-yb1-f181.google.com ([209.85.219.181]:33938 "EHLO mail-yb1-f181.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1728776AbeIYWQ4 (ORCPT ); Tue, 25 Sep 2018 18:16:56 -0400 Received: by mail-yb1-f181.google.com with SMTP id 184-v6so10008955ybg.1 for ; Tue, 25 Sep 2018 09:08:44 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:from:date:message-id:subject:to :content-transfer-encoding; bh=iPYHfmz3obpOB3SPYCkGrIiUNvjJMyYyp88aK8/+r24=; b=WI41b5WOG7AdzI/OimMmRImzzJ/GTc/gUdHfalFZcasFDRjC++a8OyMOYvwbhsbbk/ lexLvTR416zz84yrhy92X+KUuMoEdd0zeyi7tI9TMTJrfBkKRzg/XNxhNIPLN8I1BkAn OOPchpKBqXhDmu3W9Z9R4Y/Wr1cGUtVCu161H8+O+RosQJxPIbc8bECTCrMP/PZFRqca /thyOyiu5EfrL26nd7qiV/gnH/UK0JXX4SBN7J2UL/W8n+lPlW2biwkj4uFfmU0Cr8DK WCNbkja47s71tAF9IrKfh78puq7CKuIhCihP0KFOMEF3EFiTsPo5rsfYnFelecfjJMR0 ALug== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:from:date:message-id:subject:to :content-transfer-encoding; bh=iPYHfmz3obpOB3SPYCkGrIiUNvjJMyYyp88aK8/+r24=; b=gcFevuzfIIOBFh76svMlLaJB5S1fXa7qN0b5rOvBRX0qRNfRHN21xg2H6JIiOTEtAw vsYGAyYHGx3TjL55w5g2EOEB7y9EZ/jpWgNAry0NI1vdh9lVSGDc0Ed0s+HnKzdFmXoh aDaoqavgj6NWHKKS0/q1cfalIa+dK+AM09MKZtt5Xcsqnmc03wiRJ0cO4dkYk+wvdeOQ wFas7d7fY7PfhHT5loQA42le/8nD9fMSzVCde//49qf622rzbQtGgZyqrIlLj1vS1iMC 53wSq4ZU5SbS0fFdiLGzxN/YFq+6pnVj5hhY56kmafTY77DfzH1CcpZtrHCQ1fdTPvh7 xlnw== X-Gm-Message-State: ABuFfohgDYYaz/TbgrWpUfBSbHfk0dx2FS7eFg/yaHlAthgb7rwDQJCk XEbQOesCsjBf+Zsu2T/9bwaada8gQVE6Ww0MvrGGQ39V X-Google-Smtp-Source: ACcGV60IHuC0qwTOTs/pkHQCLncFntw0WfdxAenmpn9iD26ubDGFg6SO+GM/bFc9tq0TAgKUDIxcA0MLPLULAeSqsg4= X-Received: by 2002:a25:7d02:: with SMTP id y2-v6mr958514ybc.515.1537891723420; Tue, 25 Sep 2018 09:08:43 -0700 (PDT) MIME-Version: 1.0 From: fabien dvlt Date: Tue, 25 Sep 2018 18:08:32 +0200 Message-ID: Subject: Security block and Bluez - connection issue with Android To: linux-bluetooth@vger.kernel.org Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable Sender: linux-bluetooth-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-bluetooth@vger.kernel.org Hello, After trying 42 connections, 30% of my attempts are failing on authentication (bluez 5.47). This happens with multiple (all?) Android phones. Below are the btmon logs which I am finding interesting after that you will find the complete logs. For all of my failing connection, I saw that an L2CAP connection requests with PSM 0x19 is processed just before 'Encryption Change' event. But, for all successful attempts this L2CAP connection request is made after "Encryption Change' event. So I made a patch to postpone the involved ACL packet after the Encryption Change event and now I have 100% of success but it is still a little hackish. May be this is also related to https://www.spinics.net/lists/linux-bluetooth/msg72827.html Thank you ------------------------------ > HCI Event: Link Key Request (0x17) plen 6 = = = = #195 [hci0] 21.708115 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) < HCI Command: Link Key Request Reply (0x01|0x000b) plen 22 #196 [hci0] 21.708397 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Link key: feff6b48c953f119c1579913be0c0f65 > HCI Event: Command Complete (0x0e) plen 10 = = = = #197 [hci0] 21.710115 Link Key Request Reply (0x01|0x000b) ncmd 1 Status: Success (0x00) Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) > ACL Data RX: Handle 13 flags 0x02 dlen 12 = = = = #198 [hci0] 21.813116 L2CAP: Connection Request (0x02) ident 7 len 4 PSM: 25 (0x0019) Source CID: 75 > HCI Event: Encryption Change (0x08) plen 4 = = = = #199 [hci0] 21.813155 Status: Success (0x00) Handle: 13 Encryption: Enabled with AES-CCM (0x02) < ACL Data TX: Handle 13 flags 0x00 dlen 16 #200 [hci0] 21.813256 L2CAP: Connection Response (0x03) ident 7 len 8 Destination CID: 0 Source CID: 75 Result: Connection refused - security block (0x0003) Status: No further information available (0x0000) ------------------------------ # COMPLETE BTMON LOGS > HCI Event: Connect Request (0x04) plen 10 = = = = #152 [hci0] 21.335093 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Class: 0x5a020c Major class: Phone (cellular, cordless, payphone, modem) Minor class: Smart phone Networking (LAN, Ad hoc) Capturing (Scanner, Microphone) Object Transfer (v-Inbox, v-Folder) Telephony (Cordless telephony, Modem, Headset) Link type: ACL (0x01) < HCI Command: Accept Connection Request (0x01|0x0009) plen 7 #153 [hci0] 21.335196 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Role: Master (0x00) > HCI Event: Command Status (0x0f) plen 4 = = = = #154 [hci0] 21.337107 Accept Connection Request (0x01|0x0009) ncmd 1 Status: Success (0x00) > HCI Event: Role Change (0x12) plen 8 = = = = #155 [hci0] 21.589092 Status: Success (0x00) Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Role: Master (0x00) > HCI Event: Connect Complete (0x03) plen 11 = = = = #156 [hci0] 21.596088 Status: Success (0x00) Handle: 13 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Link type: ACL (0x01) Encryption: Disabled (0x00) < HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2 #157 [hci0] 21.596328 Handle: 13 > HCI Event: Command Status (0x0f) plen 4 = = = = #158 [hci0] 21.607116 Read Remote Supported Features (0x01|0x001b) ncmd 1 Status: Success (0x00) > HCI Event: Page Scan Repetition Mode Change (0x20) plen 7 = = = = #159 [hci0] 21.608112 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Page scan repetition mode: R1 (0x01) > HCI Event: Max Slots Change (0x1b) plen 3 = = = = #160 [hci0] 21.609114 Handle: 13 Max slots: 5 > HCI Event: Read Remote Supported Features (0x0b) plen 11 = = = = #161 [hci0] 21.612116 Status: Success (0x00) Handle: 13 Features: 0xff 0xfe 0x8f 0xfe 0xd8 0x3f 0x5b 0x87 3 slot packets 5 slot packets Encryption Slot offset Timing accuracy Role switch Hold mode Sniff mode 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 Broadcast Encryption Enhanced Data Rate ACL 2 Mbps mode Enhanced Data Rate ACL 3 Mbps mode Enhanced inquiry scan Interlaced inquiry scan Interlaced page scan RSSI with inquiry results Extended SCO link (EV3 packets) AFH capable slave AFH classification slave LE Supported (Controller) 3-slot Enhanced Data Rate ACL packets 5-slot Enhanced Data Rate ACL packets Sniff subrating Pause encryption AFH capable master AFH classification master Enhanced Data Rate eSCO 2 Mbps mode Extended Inquiry Response Simultaneous LE and BR/EDR (Controller) Secure Simple Pairing Encapsulated PDU Non-flushable Packet Boundary Flag Link Supervision Timeout Changed Event Inquiry TX Power Level Enhanced Power Control Extended features < HCI Command: Read Remote Extended Features (0x01|0x001c) plen 3 #162 [hci0] 21.612211 Handle: 13 Page: 1 > HCI Event: Command Status (0x0f) plen 4 = = = = #163 [hci0] 21.614113 Read Remote Extended Features (0x01|0x001c) ncmd 1 Status: Success (0x00) > ACL Data RX: Handle 13 flags 0x02 dlen 10 = = = = #164 [hci0] 21.617110 L2CAP: Information Request (0x0a) ident 2 len 2 Type: Extended features supported (0x0002) > HCI Event: Read Remote Extended Features (0x23) plen 13 = = = = #165 [hci0] 21.617139 Status: Success (0x00) Handle: 13 Page: 1/2 Features: 0x0f 0x00 0x00 0x00 0x00 0x00 0x00 0x00 Secure Simple Pairing (Host Support) LE Supported (Host) Simultaneous LE and BR/EDR (Host) Secure Connections (Host Support) < HCI Command: Remote Name Request (0x01|0x0019) plen 10 #166 [hci0] 21.617258 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Page scan repetition mode: R2 (0x02) Page scan mode: Mandatory (0x00) Clock offset: 0x0000 < ACL Data TX: Handle 13 flags 0x00 dlen 10 #167 [hci0] 21.617284 L2CAP: Information Request (0x0a) ident 1 len 2 Type: Extended features supported (0x0002) < ACL Data TX: Handle 13 flags 0x00 dlen 16 #168 [hci0] 21.617307 L2CAP: Information Response (0x0b) ident 2 len 8 Type: Extended features supported (0x0002) Result: Success (0x0000) Features: 0x000002b8 Enhanced Retransmission Mode Streaming Mode FCS Option Fixed Channels Unicast Connectionless Data Reception > HCI Event: Command Status (0x0f) plen 4 = = = = #169 [hci0] 21.619110 Remote Name Request (0x01|0x0019) ncmd 1 Status: Success (0x00) > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #170 [hci0] 21.620114 Num handles: 1 Handle: 13 Count: 1 > ACL Data RX: Handle 13 flags 0x02 dlen 16 = = = = #171 [hci0] 21.622116 L2CAP: Information Response (0x0b) ident 1 len 8 Type: Extended features supported (0x0002) Result: Success (0x0000) Features: 0x000000b8 Enhanced Retransmission Mode Streaming Mode FCS Option Fixed Channels < ACL Data TX: Handle 13 flags 0x00 dlen 10 #172 [hci0] 21.622208 L2CAP: Information Request (0x0a) ident 2 len 2 Type: Fixed channels supported (0x0003) > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #173 [hci0] 21.626110 Num handles: 1 Handle: 13 Count: 1 > ACL Data RX: Handle 13 flags 0x02 dlen 10 = = = = #174 [hci0] 21.628106 L2CAP: Information Request (0x0a) ident 3 len 2 Type: Fixed channels supported (0x0003) < ACL Data TX: Handle 13 flags 0x00 dlen 20 #175 [hci0] 21.628386 L2CAP: Information Response (0x0b) ident 3 len 12 Type: Fixed channels supported (0x0003) Result: Success (0x0000) Channels: 0x0000000000000086 L2CAP Signaling (BR/EDR) Connectionless reception Security Manager (BR/EDR) > ACL Data RX: Handle 13 flags 0x02 dlen 20 = = = = #176 [hci0] 21.636079 L2CAP: Information Response (0x0b) ident 2 len 12 Type: Fixed channels supported (0x0003) Result: Success (0x0000) Channels: 0x0000000000000082 L2CAP Signaling (BR/EDR) Security Manager (BR/EDR) > ACL Data RX: Handle 13 flags 0x02 dlen 12 = = = = #177 [hci0] 21.638082 L2CAP: Connection Request (0x02) ident 4 len 4 PSM: 1 (0x0001) Source CID: 74 @ MGMT Event: Device Connected (0x000b) plen 18 {0x0002} [hci0] 21.638158 BR/EDR Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Flags: 0x00000000 Data length: 5 Class: 0x5a020c Major class: Phone (cellular, cordless, payphone, modem) Minor class: Smart phone Networking (LAN, Ad hoc) Capturing (Scanner, Microphone) Object Transfer (v-Inbox, v-Folder) Telephony (Cordless telephony, Modem, Headset) @ MGMT Event: Device Connected (0x000b) plen 18 {0x0001} [hci0] 21.638158 BR/EDR Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Flags: 0x00000000 Data length: 5 Class: 0x5a020c Major class: Phone (cellular, cordless, payphone, modem) Minor class: Smart phone Networking (LAN, Ad hoc) Capturing (Scanner, Microphone) Object Transfer (v-Inbox, v-Folder) Telephony (Cordless telephony, Modem, Headset) < ACL Data TX: Handle 13 flags 0x00 dlen 16 #178 [hci0] 21.638233 L2CAP: Connection Response (0x03) ident 4 len 8 Destination CID: 64 Source CID: 74 Result: Connection successful (0x0000) Status: No further information available (0x0000) < ACL Data TX: Handle 13 flags 0x00 dlen 23 #179 [hci0] 21.638251 L2CAP: Configure Request (0x04) ident 3 len 15 Destination CID: 74 Flags: 0x0000 Option: Retransmission and Flow Control (0x04) [mandatory] Mode: Basic (0x00) TX window size: 0 Max transmit: 0 Retransmission timeout: 0 Monitor timeout: 0 Maximum PDU size: 0 > HCI Event: Remote Name Req Complete (0x07) plen 255 = = = = #180 [hci0] 21.643122 Status: Success (0x00) Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Name: OnePlus 6 > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #181 [hci0] 21.644131 Num handles: 1 Handle: 13 Count: 1 > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #182 [hci0] 21.645124 Num handles: 1 Handle: 13 Count: 1 > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #183 [hci0] 21.648116 Num handles: 1 Handle: 13 Count: 1 > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #184 [hci0] 21.649120 Num handles: 1 Handle: 13 Count: 1 > ACL Data RX: Handle 13 flags 0x02 dlen 16 = = = = #185 [hci0] 21.658113 L2CAP: Configure Request (0x04) ident 5 len 8 Destination CID: 64 Flags: 0x0000 Option: Maximum Transmission Unit (0x01) [mandatory] MTU: 672 < ACL Data TX: Handle 13 flags 0x00 dlen 18 #186 [hci0] 21.658194 L2CAP: Configure Response (0x05) ident 5 len 10 Source CID: 74 Flags: 0x0000 Result: Success (0x0000) Option: Maximum Transmission Unit (0x01) [mandatory] MTU: 672 > ACL Data RX: Handle 13 flags 0x02 dlen 14 = = = = #187 [hci0] 21.659124 L2CAP: Configure Response (0x05) ident 3 len 6 Source CID: 64 Flags: 0x0000 Result: Success (0x0000) > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #188 [hci0] 21.661118 Num handles: 1 Handle: 13 Count: 1 > ACL Data RX: Handle 13 flags 0x02 dlen 28 = = = = #189 [hci0] 21.663116 Channel: 64 len 24 [PSM 1 mode 0] {chan 0} SDP: Service Search Attribute Request (0x06) tid 0 len 19 Search pattern: [len 5] Sequence (6) with 3 bytes [8 extra bits] len 5 UUID (3) with 2 bytes [0 extra bits] len 3 Audio Sink (0x110b) Max record count: 656 Attribute list: [len 11] Sequence (6) with 9 bytes [8 extra bits] len 11 Unsigned Integer (1) with 2 bytes [0 extra bits] len 3 0x0001 Unsigned Integer (1) with 2 bytes [0 extra bits] len 3 0x0004 Unsigned Integer (1) with 2 bytes [0 extra bits] len 3 0x0009 Continuation state: 0 < ACL Data TX: Handle 13 flags 0x00 dlen 58 #190 [hci0] 21.663513 Channel: 74 len 54 [PSM 1 mode 0] {chan 0} SDP: Service Search Attribute Response (0x07) tid 0 len 49 Attribute bytes: 46 Attribute list: [len 42] {position 0} Attribute: Service Class ID List (0x0001) [len 2] UUID (3) with 2 bytes [0 extra bits] len 3 Audio Sink (0x110b) Attribute: Protocol Descriptor List (0x0004) [len 2] Sequence (6) with 6 bytes [8 extra bits] len 8 UUID (3) with 2 bytes [0 extra bits] len 3 L2CAP (0x0100) Unsigned Integer (1) with 2 bytes [0 extra bits] len 3 0x0019 Sequence (6) with 6 bytes [8 extra bits] len 8 UUID (3) with 2 bytes [0 extra bits] len 3 AVDTP (0x0019) Unsigned Integer (1) with 2 bytes [0 extra bits] len 3 0x0103 Attribute: Bluetooth Profile Descriptor List (0x0009) [len 2] Sequence (6) with 6 bytes [8 extra bits] len 8 UUID (3) with 2 bytes [0 extra bits] len 3 Advanced Audio Distribution (0x110d) Unsigned Integer (1) with 2 bytes [0 extra bits] len 3 0x0103 Continuation state: 0 > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #191 [hci0] 21.670123 Num handles: 1 Handle: 13 Count: 1 > ACL Data RX: Handle 13 flags 0x02 dlen 12 = = = = #192 [hci0] 21.682116 L2CAP: Disconnection Request (0x06) ident 6 len 4 Destination CID: 64 Source CID: 74 < ACL Data TX: Handle 13 flags 0x00 dlen 12 #193 [hci0] 21.682230 L2CAP: Disconnection Response (0x07) ident 6 len 4 Destination CID: 64 Source CID: 74 > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #194 [hci0] 21.685121 Num handles: 1 Handle: 13 Count: 1 > HCI Event: Link Key Request (0x17) plen 6 = = = = #195 [hci0] 21.708115 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) < HCI Command: Link Key Request Reply (0x01|0x000b) plen 22 #196 [hci0] 21.708397 Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Link key: feff6b48c953f119c1579913be0c0f65 > HCI Event: Command Complete (0x0e) plen 10 = = = = #197 [hci0] 21.710115 Link Key Request Reply (0x01|0x000b) ncmd 1 Status: Success (0x00) Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) > ACL Data RX: Handle 13 flags 0x02 dlen 12 = = = = #198 [hci0] 21.813116 L2CAP: Connection Request (0x02) ident 7 len 4 PSM: 25 (0x0019) Source CID: 75 > HCI Event: Encryption Change (0x08) plen 4 = = = = #199 [hci0] 21.813155 Status: Success (0x00) Handle: 13 Encryption: Enabled with AES-CCM (0x02) < ACL Data TX: Handle 13 flags 0x00 dlen 16 #200 [hci0] 21.813256 L2CAP: Connection Response (0x03) ident 7 len 8 Destination CID: 0 Source CID: 75 Result: Connection refused - security block (0x0003) Status: No further information available (0x0000) < HCI Command: Read Encryption Key Size (0x05|0x0008) plen 2 #201 [hci0] 21.813277 Handle: 13 > HCI Event: Command Complete (0x0e) plen 7 = = = = #202 [hci0] 21.815118 Read Encryption Key Size (0x05|0x0008) ncmd 1 Status: Success (0x00) Handle: 13 Key size: 16 > HCI Event: Number of Completed Packets (0x13) plen 5 = = = = #203 [hci0] 21.816118 Num handles: 1 Handle: 13 Count: 1 < HCI Command: Disconnect (0x01|0x0006) plen 3 #204 [hci0] 25.727125 Handle: 13 Reason: Authentication Failure (0x05) > HCI Event: Command Status (0x0f) plen 4 = = = = #205 [hci0] 25.729069 Disconnect (0x01|0x0006) ncmd 1 Status: Success (0x00) > HCI Event: Disconnect Complete (0x05) plen 4 = = = = #206 [hci0] 25.738073 Status: Success (0x00) Handle: 13 Reason: Connection Terminated By Local Host (0x16) @ MGMT Event: Device Disconnected (0x000c) plen 8 {0x0002} [hci0] 25.738149 BR/EDR Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Reason: Connection terminated by local host (0x02) @ MGMT Event: Device Disconnected (0x000c) plen 8 {0x0001} [hci0] 25.738149 BR/EDR Address: 64:A2:F9:XX:XX:XX (OUI 64-A2-F9) Reason: Connection terminated by local host (0x02)