Open Radar

 
Chaoqun Zou11-Aug-2016 01:49 PM

Hi, I used an app "BlueChat" to capture the logs. (https://github.com/zouchaoqun/BlueChat)

The BlueChat app works in both Central and Peripheral roles. In the test I had two devices, one iPhone working as peripheral, one iPad mini working as central and the logs are from the iPad mini (iOS 9.3.4). 
(the iPhone is running on iOS 10 beta 5, but if you try iOS 9 it will be the same result) 

I tried two scenarios which are both included in the logs:

(log entries mentioned below are from BTServer_2016_08_11_12_15_56+0930.log)

Scenario 1: 
(1) from iPad mini, use the BlueChat app (central) to connect to the BlueChat app (peripheral) running on iPhone
(2) from iPad mini, write to a characteristic with permission CBAttributePermissionsWriteEncryptionRequired
(3) there should be Pairing popups on both the iPhone and the iPad, choose Pair on both ends
(4) from iPad mini, we can see the didWriteValueForCharacteristic:error: callback is invoked correctly

{logs}
2016-08-11T12:22:15.546 XpcLeConnection.cpp:57    handleMsg            Notice     XPC        Received XPC message "CBMsgIdCharacteristicWriteValue" from session "com.schneider-electric.BlueChat-central-321-1"
2016-08-11T12:22:15.546 GattGateway.cpp:437       writeCharacteristic  Notice     ATT        Writing value with response to characteristic handle 0x0045 on device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
2016-08-11T12:22:15.547 GattCommands.cpp:1159     runCommand           Notice     ATT        Using Write Characteristic value
2016-08-11T12:22:15.601 XpcLeConnection.cpp:95    sendMsg              Notice     XPC        Sending XPC message "CBMsgIdCharacteristicValueWritten" to session "com.schneider-electric.BlueChat-central-321-1"
{logs}


Scenario 2 (continuing scenario 1):
(5) on the iPhone, go to Settings -> Bluetooth, forget the iPad mini
(6) from the iPad mini, try to write to the same characteristic again
(7) didWriteValueForCharacteristic:error: callback is NOT invoked (from the logs we can see there is a line saying the encryption was disabled, but no XPC message is sent back to the user app)

{logs-1}
2016-08-11T12:23:25.862 XpcLeConnection.cpp:57    handleMsg            Notice     XPC        Received XPC message "CBMsgIdCharacteristicWriteValue" from session "com.schneider-electric.BlueChat-central-321-1"
2016-08-11T12:23:25.864 GattGateway.cpp:437       writeCharacteristic  Notice     ATT        Writing value with response to characteristic handle 0x0045 on device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
2016-08-11T12:23:25.864 GattCommands.cpp:1159     runCommand           Notice     ATT        Using Write Characteristic value
2016-08-11T12:23:25.913 LeDeviceManager.cpp:469   uuidForDevice        Info       LE         Already tracking address "Public 9C:35:EB:B8:1C:47" as device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
OI_ERROR> LE:224  [65535]
2016-08-11T12:23:26.033 LeSecurityManager.mm:1869 encryptionStatusChangedCb Notice     LE         encryptionStatusChangedCb handle:0x000000014A003190 status=BM3 STATUS 706 address=9C:35:EB:B8:1C:47
2016-08-11T12:23:26.033 LeDeviceManager.cpp:469   uuidForDevice        Info       LE         Already tracking address "Public 9C:35:EB:B8:1C:47" as device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
2016-08-11T12:23:26.033 LeSecurityManager.mm:1492 encryptionStatusChanged Notice     LE         Encryption is now disabled for device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74" (9C:35:EB:B8:1C:47)
2016-08-11T12:23:27.098 SystemSettings.cpp:495    ___ZN2BT14SystemSettings18takePowerAssertionEt_block_invoke_2 Notice     Core       Releasing power assertion
{logs-1}

then I tried to write again after about 15 seconds and still no callback
{logs-2}
......some log entries omitted......
2016-08-11T12:23:42.352 XpcLeConnection.cpp:57    handleMsg            Notice     XPC        Received XPC message "CBMsgIdCharacteristicWriteValue" from session "com.schneider-electric.BlueChat-central-321-1"
2016-08-11T12:23:42.352 GattGateway.cpp:437       writeCharacteristic  Notice     ATT        Writing value with response to characteristic handle 0x0045 on device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
2016-08-11T12:23:45.367 AppManager.cpp:1350       disconnectUnusedDevices Info       Core       Session "com.schneider-electric.BlueChat-central-321-1" wants connected device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
{logs-2}

then I tried again after about 1 minute and still no callback
{logs-3}
......some log entries omitted......
2016-08-11T12:24:40.424 AppManager.cpp:1350       disconnectUnusedDevices Info       Core       Session "com.schneider-electric.BlueChat-central-321-1" wants connected device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
2016-08-11T12:24:41.133 XpcLeConnection.cpp:57    handleMsg            Notice     XPC        Received XPC message "CBMsgIdCharacteristicWriteValue" from session "com.schneider-electric.BlueChat-central-321-1"
2016-08-11T12:24:41.134 GattGateway.cpp:437       writeCharacteristic  Notice     ATT        Writing value with response to characteristic handle 0x0045 on device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
2016-08-11T12:24:45.429 AppManager.cpp:1350       disconnectUnusedDevices Info       Core       Session "com.schneider-electric.BlueChat-central-321-1" wants connected device "400AE3F9-AE8E-06B2-0C68-351B7B83BE74"
2016-08-11T12:24:46.342 XpcConnection.cpp:58      handleEvent          Notice     XPC        Closed XPC connection to session "com.schneider-electric.BlueChat-peripheral-321-0"
{logs-3}

'Logs-2016.8.11-12.25.18.zip' was successfully uploaded.
Apple Developer Relations11-Aug-2016 06:20 AM

Engineering has requested the following information in order to further investigate this issue:

Please collect Bluetooth logs and attach them to your bug report.

iOS Bluetooth Logging Instructions:
https://developer.apple.com/services-account/download?path=/iOS/iOS_Logs/Bluetooth_Logging_Instructions__iPhone_and_Apple_Watch.pdf

iOS Bluetooth Logging Profile:
https://developer.apple.com/services-account/download?path=/iOS/iOS_Logs/bluetoothwirelessproximity.mobileconfig

____________________________________
For a complete list of logging instructions visit:
https://developer.apple.com/bug-reporting/profiles-and-logs/
Chaoqun Zou09-Aug-2016 11:14 AM

Hi, there is not really related logs for this issue. I am not very sure what you are looking for. Can you please let me know what else do you need?
Apple Developer Relations09-Aug-2016 02:45 AM

Please attach any relevant crash logs, panic logs, stackshots, baseband logs, etc which may have been generated automatically. If none were, install the appropriate logging profile, reproduce the issue, then attach relevant logs.

For a complete list of logging instructions visit:
https://developer.apple.com/bug-reporting/profiles-and-logs/

Please provide your response or results by updating your bug report.  If uploading files, please compress first.
Chaoqun Zou08-Aug-2016 09:30 AM

Summary:
This relates to #27579701

We are developing a simple BLE peripheral with Just works pairing and we recently found an issue in the pairing. So the issue happens like this:

(1) Pair the iPhone to the peripheral for the first time and it works fine (our peripheral rejects the read request with Insufficient Authentication correctly and we can see the iOS Pairing popup and Pairing succeeds)
(2) Remove the bonding record of the iPhone from the peripheral (the iPhone still remembers the peripheral)
(3) Use the same iPhone to connect to the device again and our peripheral still rejects the read request with Insufficient Authentication correctly but iOS does not give any error that the read request has failed in the didUpdateValueForCharacteristic (actually didUpdateValueForCharacteristic is not called after the read failure)

I can reproduce the same problem between two iPhones (tried iOS 9 and 10 beta). e.g. pair two iPhones first, then forget the other party on one phone, when the other phone tries to connect again it can't connect and it does not show the Pairing popup either.

Steps to Reproduce:
(1) Run BLE test app on two iPhones, one as central the other as peripheral. the test app should include at least one characteristic with GATT_PERMIT_AUTHEN_READ and  GATT_PERMIT_AUTHEN_WRITE
(2) From the central role, connect to the peripheral role and try to read that characteristic
(3) there should be a pairing dialog asking for pairing, pair
(4) verify the central can read and write correctly
(5) on the peripheral go to Settings - Bluetooth and forget the central iPhone
(6) use the central iPhone to connect and read the characteristic again, you will see it can't read, but the didUpdateValueForCharacteristic will never be called

Expected Results:
In step (6) didUpdateValueForCharacteristic should be called with an error like CBATTErrorInsufficientEncryption so we know the read has failed.

Actual Results:
In step (6) didUpdateValueForCharacteristic is never called 

Version:
iOS 9.3.3 iOS 10 beta 4

Notes:


Configuration:
iPhone 5S iPad Pro 9.7

Attachments: