robotastic / ble-ancs

A NodeJS library for Apple Notification Center Service over BLE
MIT License
80 stars 15 forks source link

Unexpected disconnect #8

Open deamons opened 8 years ago

deamons commented 8 years ago

Seems like ble-ansc is still the only possible way to get ANCS on raspberry. Got the script working and I can connect to the BLE device but after a few moments it just disconnects or with LightBlue I get an connection Alert Timeout interrogating the peripheral. consol log: Bleno: Handle: 68 UUID: 7069df31ed53 address 70:69:... on -> accept: Recieved a Pairing Request Hande:68 uuid: 7069df31ed53 Got a disconnect Got a disconnect Got a disconnect Got a disconnect Able: unknown peripheral 70:69:df:.. disconnected! Is this a problem with iOS 9 or a configuration problem? Is this project still working?

ghost commented 8 years ago

Hello, I'm facing the same issues:

on -> stateChange: poweredOn
on -> advertisingStart: success
Bleno: Handle: 69 UUID: 4f1ea7 address 4f:1e:a7
on -> accept: 
Recieved a Pairing Request
able encryptChange!!!
Adding to the queue: 0 attributeId: 1 queue: 0
Unqueing req, length: 0
Adding to the queue: 1 attributeId: 1 queue: 0
Adding to the queue: 0 attributeId: 4 queue: 1
Unqueing req, length: 1
Adding to the queue: 1 attributeId: 4 queue: 1
Unqueing req, length: 1
        Hande:69    uuid: 4f1ea7
Got a disconnect
Got a disconnect
Got a disconnect
Able: unknown peripheral 4f:1e:a7: disconnected!

Tested with Raspbian Jessie on RPi3 and iPhone4S v8.1.1

deamons commented 8 years ago

Full debug log on Raspbian Jessie RPi1B with iPhone 6S iOS 9.3.1. I can't figure out whats going wrong.

hci setting filter to: 1600000020c10000000000400000 +0ms
  hci set event mask - writing: 01010c08fffffbff07f8bf3d +199ms
  hci set le event mask - writing: 010120081f00000000000000 +90ms
  hci read local version - writing: 01011000 +9ms
  hci read bd addr - writing: 01091000 +10ms
  hci onSocketData: 040e0401010c00  event type = 4 +516ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +10ms
  hci       cmd = 3073 +9ms
  hci       status = 0 +7ms
  hci       result =  +6ms
  hci ! Unhandled Command: 3073 +23ms
  hci onSocketData: 040e0401012000  event type = 4 +10ms
  hci   sub event type = 14 +9ms
  hci       EVT_CMD_COMPLETE +8ms
  hci       cmd = 8193 +6ms
  hci       status = 0 +7ms
  hci       result =  +4ms
  hci ! Unhandled Command: 8193 +6ms
  hci onSocketData: 040e0c0101100006bb22060a00bb22  event type = 4 +10ms
  hci   sub event type = 14 +8ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 4097 +5ms
  hci       status = 0 +5ms
  hci       result = 06bb22060a00bb22 +7ms
  hci set scan enabled - writing: 010c20020001 +15ms
  hci set scan parameters - writing: 010b200701100010000000 +12ms
  hci       READ_LOCAL_VERSION_CMD +5ms
  hci onSocketData: 040e0a010910001371da7d1a00  event type = 4 +12ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +8ms
  hci       cmd = 4105 +5ms
  hci       status = 0 +6ms
  hci       result = 1371da7d1a00 +10ms
  hci       READ_BD_ADDR_CMD +34ms
  Able addressChange 00:1a:7d:da:71:13 +15ms
  Able addressChange 00:1a:7d:da:71:13 +27ms
  hci onSocketData: 040e04010c200c  event type = 4 +6ms
  hci   sub event type = 14 +8ms
  hci       EVT_CMD_COMPLETE +4ms
  hci       cmd = 8204 +4ms
  hci       status = 12 +4ms
  hci       result =  +6ms
  hci       LE_SET_SCAN_ENABLE_CMD +4ms
  hci onSocketData: 040e04010b2000  event type = 4 +9ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +10ms
  hci       cmd = 8203 +3ms
  hci       status = 0 +7ms
  hci       result =  +2ms
  Able stateChange poweredOn +7ms
on -> stateChange: poweredOn
  gap startAdvertisingWithEIRData: advertisement data = 0201050a09414e4252215475736b03194002, scan data = 1115d0002d121e4b0fa4994eceb531f40579 +190ms
  hci set scan response data - writing: 01092020121115d0002d121e4b0fa4994eceb531f4057900000000000000000000000000 +18ms
  hci set advertisement data - writing: 01082020120201050a09414e4252215475736b0319400200000000000000000000000000 +15ms
  hci set advertise enable - writing: 010a200101 +10ms
  hci       LE_SET_SCAN_PARAMETERS_CMD +5ms
  hci onSocketData: 040e0401092000  event type = 4 +42ms
  hci   sub event type = 14 +8ms
  hci       EVT_CMD_COMPLETE +10ms
  hci       cmd = 8201 +4ms
  hci       status = 0 +8ms
  hci       result =  +3ms
  hci       LE_SET_SCAN_RESPONSE_DATA_CMD +3ms
  hci onSocketData: 040e0401082000  event type = 4 +6ms
  hci   sub event type = 14 +9ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 8200 +5ms
  hci       status = 0 +5ms
  hci       result =  +4ms
  hci       LE_SET_ADVERTISING_DATA_CMD +3ms
  hci onSocketData: 040e04010a200c  event type = 4 +9ms
  hci   sub event type = 14 +5ms
  hci       EVT_CMD_COMPLETE +11ms
  hci       cmd = 8202 +5ms
  hci       status = 12 +7ms
  hci       result =  +4ms
  hci       LE_SET_ADVERTISE_ENABLE_CMD +4ms
  Able advertisingStart: Error: Unknown (12) +45ms
on -> advertisingStart: error Error: Unknown (12)
  local-gatt handles = [
  {},
  {
    "type": "service",
    "uuid": "1800",
    "startHandle": 1,
    "endHandle": 5
  },
  {
    "type": "characteristic",
    "uuid": "2a00",
    "properties": 2,
    "secure": 2,
    "startHandle": 2,
    "valueHandle": 3
  },
  {
    "type": "characteristicValue",
    "handle": 3,
    "value": "Buffer('626c652d616e6373', 'hex')"
  },
  {
    "type": "characteristic",
    "uuid": "2a01",
    "properties": 2,
    "secure": 0,
    "startHandle": 4,
    "valueHandle": 5
  },
  {
    "type": "characteristicValue",
    "handle": 5,
    "value": "Buffer('8000', 'hex')"
  },
  {
    "type": "service",
    "uuid": "1801",
    "startHandle": 6,
    "endHandle": 9
  },
  {
    "type": "characteristic",
    "uuid": "2a05",
    "properties": 32,
    "secure": 32,
    "startHandle": 7,
    "valueHandle": 8
  },
  {
    "type": "characteristicValue",
    "handle": 8,
    "value": "Buffer('00000000', 'hex')"
  },
  {
    "type": "descriptor",
    "handle": 9,
    "uuid": "2902",
    "properties": 14,
    "secure": 0,
    "value": "Buffer('0000', 'hex')"
  },
  {
    "type": "service",
    "uuid": "13333333333333333333333333333337",
    "startHandle": 10,
    "endHandle": 14
  },
  {
    "type": "characteristic",
    "uuid": "2803",
    "properties": 2,
    "secure": 2,
    "startHandle": 11,
    "valueHandle": 12
  },
  {
    "type": "characteristicValue",
    "handle": 12,
    "value": null
  },
  {
    "type": "descriptor",
    "handle": 13,
    "uuid": "2901",
    "properties": 2,
    "secure": 0,
    "value": "Generic!"
  },
  {
    "type": "descriptor",
    "handle": 14,
    "uuid": "2904",
    "properties": 2,
    "secure": 0,
    "value": "Buffer('040127ad010000', 'hex')"
  }
] +213ms
  bindings Trying to set services +26ms
  Able servicesSet +4ms
  hci onSocketData: 043e130100450001010d01e0ec9c5818000000480005    event type = 4 +1m
  hci   sub event type = 62 +19ms
  hci       EVT_LE_META_EVENT +6ms
  hci       LE meta event type = 1 +13ms
  hci       LE meta event status = 0 +7ms
  hci       LE meta event data = 450001010d01e0ec9c5818000000480005 +7ms
  hci           handle = 69 +44ms
  hci           role = 1 +7ms
  hci           address type = random +8ms
  hci           address = 58:9c:ec:e0:01:0d +7ms
  hci           interval = 30 +8ms
  hci           latency = 0 +11ms
  hci           supervision timeout = 720 +4ms
  hci           master clock accuracy = 5 +11ms
  bindings onLeConnComplete -  status: 0 role: 1 Address: 58:9c:ec:e0:01:0d Type: random +36ms
  gatt Sending ATT_OP_MTU_REQ: 256 +308ms
  gatt 1 Commands in Queue +15ms
  gatt 58:9c:ec:e0:01:0d: write: 020001 +7ms
  hci write acl data pkt - writing: 024500070003000400020001 +14ms
Bleno: Handle: 69 UUID: 589cece0010d address 58:9c:ec:e0:01:0d
  Able accept random +20ms
on -> accept: 
  hci onSocketData: 02450010000c000500120108002800380000004800  event type = 2 +22ms
  hci onSocketData: 0245200a0006000500130102000000  event type = 2 +9ms
  hci       HCI_ACLDATA_PKT - ACL_START +6ms
  hci       cid = 5 +7ms
  hci       type =  Unhandled: 19 +17ms
  hci       handle = 69 +8ms
  hci       data = 130102000000 +5ms
  hci onSocketData: 024520070003000400029e00    event type = 2 +11ms
  hci       HCI_ACLDATA_PKT - ACL_START +9ms
  hci       cid = 4 +4ms
  hci       type = ATT_OP_MTU_REQ:  +6ms
  hci       handle = 69 +7ms
  hci       data = 029e00 +4ms
  local-gatt ATT_OP_MTU_REQ:  +9ms
  Able mtu 158 +13ms
  local-gatt Response - Sending MTU: 158 +7ms
  local-gatt response: 039e00 +6ms
  hci write acl data pkt - writing: 024500070003000400039e00 +13ms
  hci onSocketData: 0245201b0018003a00011601140100020f636f6d2e6170706c652e42542e5453    event type = 2 +8ms
  hci       HCI_ACLDATA_PKT - ACL_START +7ms
  hci       cid = 58 +6ms
  hci       type = ATT_OP_ERROR:  +3ms
  hci onSocketData: 024510010001    event type = 2 +8ms
  hci       HCI_ACLDATA_PKT - ACL_CONT +6ms
  hci       COMPLETE +17ms
  hci onSocketData: 0245200b0007003a0009050100000000    event type = 2 +10ms
  hci       HCI_ACLDATA_PKT - ACL_START +6ms
  hci       cid = 58 +10ms
  hci       type = ATT_OP_READ_BY_TYPE_RESP:  +3ms
  hci       handle = 69 +7ms
  hci       data = 09050100000000 +5ms
  hci onSocketData: 0245201b0024003a0005220200011d636f6d2e6170706c652e42544c45536572    event type = 2 +7ms
  hci       HCI_ACLDATA_PKT - ACL_START +7ms
  hci       cid = 58 +4ms
  hci       type =  Unhandled: 5 +5ms
  hci onSocketData: 0245100d007665722e636c61737369630001    event type = 2 +14ms
  hci       HCI_ACLDATA_PKT - ACL_CONT +7ms
  hci       COMPLETE +5ms
  hci onSocketData: 01011000    event type = 1 +9ms
  hci       cmd = 4097 +6ms
  hci       data len = 0 +8ms
  hci onSocketData: 040e0c0101100006bb22060a00bb22  event type = 4 +6ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 4097 +7ms
  hci       status = 0 +4ms
  hci       result = 06bb22060a00bb22 +3ms
  hci       READ_LOCAL_VERSION_CMD +9ms
  hci onSocketData: 0104100101  event type = 1 +12ms
  hci       cmd = 4100 +9ms
  hci       data len = 1 +6ms
  hci onSocketData: 040e0e0104100001010100000000000000  event type = 4 +7ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +3ms
  hci       cmd = 4100 +4ms
  hci       status = 0 +6ms
  hci       result = 01010100000000000000 +7ms
  hci ! Unhandled Command: 4100 +5ms
  hci onSocketData: 01180c020020    event type = 1 +9ms
  hci       cmd = 3096 +9ms
  hci       data len = 2 +3ms
  hci onSocketData: 040e0401180c00  event type = 4 +5ms
  hci   sub event type = 14 +5ms
  hci       EVT_CMD_COMPLETE +3ms
  hci       cmd = 3096 +5ms
  hci       status = 0 +6ms
  hci       result =  +7ms
  hci ! Unhandled Command: 3096 +4ms
  hci onSocketData: 010d0c0700000000000001  event type = 1 +8ms
  hci       cmd = 3085 +7ms
  hci       data len = 7 +3ms
  hci onSocketData: 040e08010d0c0010000000  event type = 4 +7ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 3085 +5ms
  hci       status = 0 +7ms
  hci       result = 10000000 +6ms
  hci ! Unhandled Command: 3085 +7ms
  hci onSocketData: 01011000    event type = 1 +7ms
  hci       cmd = 4097 +8ms
  hci       data len = 0 +3ms
  hci onSocketData: 040e0c0101100006bb22060a00bb22  event type = 4 +4ms
  hci   sub event type = 14 +8ms
  hci       EVT_CMD_COMPLETE +3ms
  hci       cmd = 4097 +6ms
  hci       status = 0 +8ms
  hci       result = 06bb22060a00bb22 +3ms
  hci       READ_LOCAL_VERSION_CMD +7ms
  hci onSocketData: 01130cf8416d62692d300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000    event type = 1 +10ms
  hci       cmd = 3091 +6ms
  hci       data len = 248 +8ms
  hci onSocketData: 040e0401130c00  event type = 4 +6ms
  hci   sub event type = 14 +6ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 3091 +7ms
  hci       status = 0 +3ms
  hci       result =  +4ms
  hci ! Unhandled Command: 3091 +5ms
  hci onSocketData: 043e0a03004500360000004800  event type = 4 +7ms
  hci   sub event type = 62 +5ms
  hci       EVT_LE_META_EVENT +9ms
  hci       LE meta event type = 3 +7ms
  hci       LE meta event status = 0 +6ms
  hci       LE meta event data = 4500360000004800 +5ms
  hci           handle = 69 +11ms
  hci           interval = 67.5 +32ms
  hci           latency = 0 +7ms
  hci           supervision timeout = 720 +9ms
  bindings onLeConnUpdateComplete - Not sure what to do... not doing anything +4ms
  bindings      address: 58:9c:ec:e0:01:0d +5ms
  bindings      handle: 69 +7ms
  bindings      gatt: [object Object] +6ms
  bindings      handles: 589cece0010d +8ms
  hci onSocketData: 01010c08fffffbff07f8bf3d    event type = 1 +7ms
  hci       cmd = 3073 +6ms
  hci       data len = 8 +4ms
  hci onSocketData: 040e0401010c00  event type = 4 +9ms
  hci   sub event type = 14 +4ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 3073 +6ms
  hci       status = 0 +4ms
  hci       result =  +7ms
  hci ! Unhandled Command: 3073 +4ms
  hci onSocketData: 01560c0101  event type = 1 +8ms
  hci       cmd = 3158 +7ms
  hci       data len = 1 +4ms
  hci onSocketData: 040e0401560c00  event type = 4 +6ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +11ms
  hci       cmd = 3158 +3ms
  hci       status = 0 +5ms
  hci       result =  +5ms
  hci ! Unhandled Command: 3158 +3ms
  hci onSocketData: 01450c0102  event type = 1 +7ms
  hci       cmd = 3141 +8ms
  hci       data len = 1 +6ms
  hci onSocketData: 040e0401450c00  event type = 4 +6ms
  hci   sub event type = 14 +6ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 3141 +6ms
  hci       status = 0 +5ms
  hci       result =  +3ms
  hci ! Unhandled Command: 3141 +7ms
  hci onSocketData: 01580c00    event type = 1 +5ms
  hci       cmd = 3160 +9ms
  hci       data len = 0 +5ms
  hci onSocketData: 040e0501580c0004    event type = 4 +6ms
  hci   sub event type = 14 +9ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 3160 +4ms
  hci       status = 0 +4ms
  hci       result = 04 +5ms
  hci ! Unhandled Command: 3160 +7ms
  hci onSocketData: 010f08020f00    event type = 1 +7ms
  hci       cmd = 2063 +8ms
  hci       data len = 2 +5ms
  hci onSocketData: 040e04010f0800  event type = 4 +4ms
  hci   sub event type = 14 +6ms
  hci       EVT_CMD_COMPLETE +4ms
  hci       cmd = 2063 +6ms
  hci       status = 0 +5ms
  hci       result =  +10ms
  hci ! Unhandled Command: 2063 +6ms
  hci onSocketData: 01240c03000142  event type = 1 +7ms
  hci       cmd = 3108 +7ms
  hci       data len = 3 +4ms
  hci onSocketData: 040e0401240c00  event type = 4 +6ms
  hci   sub event type = 14 +8ms
  hci       EVT_CMD_COMPLETE +3ms
  hci       cmd = 3108 +4ms
  hci       status = 0 +6ms
  hci       result =  +6ms
  hci ! Unhandled Command: 3108 +5ms
  hci onSocketData: 011a0c0102  event type = 1 +7ms
  hci       cmd = 3098 +9ms
  hci       data len = 1 +4ms
  hci onSocketData: 040e04011a0c00  event type = 4 +7ms
  hci   sub event type = 14 +6ms
  hci       EVT_CMD_COMPLETE +9ms
  hci       cmd = 3098 +4ms
  hci       status = 0 +5ms
  hci       result =  +4ms
  hci ! Unhandled Command: 3098 +5ms
  hci onSocketData: 01020400    event type = 1 +8ms
  hci       cmd = 1026 +7ms
  hci       data len = 0 +5ms
  hci onSocketData: 040e040102040c  event type = 4 +7ms
  hci   sub event type = 14 +12ms
  hci       EVT_CMD_COMPLETE +1ms
  hci       cmd = 1026 +4ms
  hci       status = 12 +7ms
  hci       result =  +3ms
  hci ! Unhandled Command: 1026 +5ms
  hci onSocketData: 01140c00    event type = 1 +7ms
  hci       cmd = 3092 +7ms
  hci       data len = 0 +5ms
  hci onSocketData: 040efc01140c00416d62692d300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000  event type = 4 +10ms
  hci   sub event type = 14 +5ms
  hci       EVT_CMD_COMPLETE +4ms
  hci       cmd = 3092 +6ms
  hci       status = 0 +7ms
  hci       result = 416d62692d300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 +8ms
  hci ! Unhandled Command: 3092 +5ms
  hci onSocketData: 01550c00    event type = 1 +6ms
  hci       cmd = 3157 +9ms
  hci       data len = 0 +5ms
  hci onSocketData: 040e0501550c0001    event type = 4 +7ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +5ms
  hci       cmd = 3157 +6ms
  hci       status = 0 +3ms
  hci       result = 01 +8ms
  hci ! Unhandled Command: 3157 +4ms
  hci onSocketData: 01190c00    event type = 1 +7ms
  hci       cmd = 3097 +9ms
  hci       data len = 0 +4ms
  hci onSocketData: 040e0501190c0002    event type = 4 +7ms
  hci   sub event type = 14 +5ms
  hci       EVT_CMD_COMPLETE +6ms
  hci       cmd = 3097 +4ms
  hci       status = 0 +5ms
  hci       result = 02 +3ms
  hci ! Unhandled Command: 3097 +6ms
  hci onSocketData: 01520cf1000709416d62692d30020a040d032d1112111f110c110e1103110000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000  event type = 1 +6ms
  hci       cmd = 3154 +8ms
  hci       data len = 241 +4ms
  hci onSocketData: 040e0401520c00  event type = 4 +6ms
  hci   sub event type = 14 +7ms
  hci       EVT_CMD_COMPLETE +7ms
  hci       cmd = 3154 +3ms
  hci       status = 0 +7ms
  hci       result =  +5ms
  hci ! Unhandled Command: 3154 +3ms
  hci onSocketData: 024520070003000400039e00    event type = 2 +5ms
  hci       HCI_ACLDATA_PKT - ACL_START +8ms
  hci       cid = 4 +6ms
  hci       type =  Unhandled: 3 +3ms
  hci       handle = 69 +5ms
  hci       data = 039e00 +6ms
  gatt 58:9c:ec:e0:01:0d: There is a current command +9ms
  gatt Echange Mtu: 158 +7ms
  gatt 58:9c:ec:e0:01:0d: new MTU is 158 +6ms
  Able mtu 158 +7ms
  hci onSocketData: 0245200b0007000400100100ffff0028    event type = 2 +8ms
  hci       HCI_ACLDATA_PKT - ACL_START +7ms
  hci       cid = 4 +6ms
  hci       type = ATT_OP_READ_BY_GROUP_REQ:  +4ms
  hci       handle = 69 +7ms
  hci       data = 100100ffff0028 +15ms
  local-gatt ATT_OP_READ_BY_GROUP_REQ:  +5ms
  local-gatt Handle read by group request: startHandle = 0x1, endHandle = 0xffff, uuid = 0x2800 +34ms
  local-gatt         Handle: 2 UUID: 2a00 Service Type: characteristic +7ms
  local-gatt         Handle: undefined UUID: undefined Service Type: characteristicValue +10ms
  local-gatt         Handle: 4 UUID: 2a01 Service Type: characteristic +6ms
  local-gatt         Handle: undefined UUID: undefined Service Type: characteristicValue +8ms
  local-gatt         Handle: 7 UUID: 2a05 Service Type: characteristic +5ms
  local-gatt         Handle: undefined UUID: undefined Service Type: characteristicValue +5ms
  local-gatt         Handle: undefined UUID: 2902 Service Type: descriptor +6ms
  local-gatt         Handle: 11 UUID: 2803 Service Type: characteristic +4ms
  local-gatt         Handle: undefined UUID: undefined Service Type: characteristicValue +6ms
  local-gatt         Handle: undefined UUID: 2901 Service Type: descriptor +3ms
  local-gatt         Handle: undefined UUID: 2904 Service Type: descriptor +4ms
  local-gatt        No handle for: 15 +10ms
  local-gatt        UUID length wrong for: 2 UUID: 13333333333333333333333333333337 +7ms
  local-gatt        Found 2 services, max is: 26 +12ms
  local-gatt response: 1106010005000018060009000118 +14ms
  hci write acl data pkt - writing: 02450012000e0004001106010005000018060009000118 +6ms
  hci onSocketData: 0245200b0007000400100a00ffff0028    event type = 2 +97ms
  hci       HCI_ACLDATA_PKT - ACL_START +6ms
  hci       cid = 4 +5ms
  hci       type = ATT_OP_READ_BY_GROUP_REQ:  +4ms
  hci       handle = 69 +8ms
  hci       data = 100a00ffff0028 +3ms
  local-gatt ATT_OP_READ_BY_GROUP_REQ:  +5ms
  local-gatt Handle read by group request: startHandle = 0xa, endHandle = 0xffff, uuid = 0x2800 +9ms
  local-gatt         Handle: 11 UUID: 2803 Service Type: characteristic +6ms
  local-gatt         Handle: undefined UUID: undefined Service Type: characteristicValue +5ms
  local-gatt         Handle: undefined UUID: 2901 Service Type: descriptor +4ms
  local-gatt         Handle: undefined UUID: 2904 Service Type: descriptor +6ms
  local-gatt        No handle for: 15 +6ms
  local-gatt        Found 1 services, max is: 7 +6ms
  local-gatt response: 11140a000e0037333333333333333333333333333313 +11ms
  hci write acl data pkt - writing: 0245001a001600040011140a000e0037333333333333333333333333333313 +4ms
  hci onSocketData: 0245200b0007000400100f00ffff0028    event type = 2 +115ms
  hci       HCI_ACLDATA_PKT - ACL_START +2ms
  hci       cid = 4 +1ms
  hci       type = ATT_OP_READ_BY_GROUP_REQ:  +2ms
  hci       handle = 69 +1ms
  hci       data = 100f00ffff0028 +2ms
  local-gatt ATT_OP_READ_BY_GROUP_REQ:  +3ms
  local-gatt Handle read by group request: startHandle = 0xf, endHandle = 0xffff, uuid = 0x2800 +6ms
  local-gatt        No handle for: 15 +4ms
  local-gatt Nothing found for group +6ms
  local-gatt response: 01100f000a +9ms
  hci write acl data pkt - writing: 02450009000500040001100f000a +5ms
  hci onSocketData: 0245200b00070004000801000500002a    event type = 2 +161ms
  hci       HCI_ACLDATA_PKT - ACL_START +5ms
  hci       cid = 4 +5ms
  hci       type = ATT_OP_READ_BY_TYPE_REQ: +8ms
  hci       handle = 69 +4ms
  hci       data = 0801000500002a +7ms
  local-gatt ATT_OP_READ_BY_TYPE_REQ: +5ms
  local-gatt read by type: startHandle = 0x1, endHandle = 0x5, uuid = 0x2a00 +30ms
  local-gatt        Responding with Charecteristic +5ms
  local-gatt ATT_ECODE_AUTHENTICATION +10ms
  local-gatt response: 0108010005 +6ms
  hci write acl data pkt - writing: 0245000900050004000108010005 +5ms
  hci onSocketData: 0245200b00070006000104000d100303    event type = 2 +112ms
  hci       HCI_ACLDATA_PKT - ACL_START +6ms
  hci       cid = 6 +6ms
  hci       type = ATT_OP_ERROR:  +5ms
  hci       handle = 69 +7ms
  hci       data = 0104000d100303 +4ms
  smp SMP Data - code: 0x1 +5ms
Recieved a Pairing Request
  smp   Should be Sending: 02030005100301 +15ms
  hci onSocketData: 0245200b000700040008060009000328    event type = 2 +30s
  hci       HCI_ACLDATA_PKT - ACL_START +7ms
  hci       cid = 4 +7ms
  hci       type = ATT_OP_READ_BY_TYPE_REQ: +3ms
  hci       handle = 69 +7ms
  hci       data = 08060009000328 +3ms
  local-gatt ATT_OP_READ_BY_TYPE_REQ: +5ms
  local-gatt read by type: startHandle = 0x6, endHandle = 0x9, uuid = 0x2803 +7ms
  local-gatt        Sending Charecteristic:     0 +9ms
  local-gatt        Start handle:   7 +6ms
  local-gatt        Properties:     20 +6ms
  local-gatt        Value Handle:   8 +4ms
  local-gatt response: 09070700200800052a +20ms
  hci write acl data pkt - writing: 0245000d000900040009070700200800052a +5ms
  hci onSocketData: 04050400450013  event type = 4 +7ms
  hci   sub event type = 5 +6ms
  hci       EVT_DISCONN_COMPLETE +7ms
  hci       handle = 69 +4ms
  hci       reason = 19 +8ms
  hci emitting disconnComplete +6ms
  bindings disconnComplete +3ms
        Hande:69    uuid: 589cece0010d
  bindings      Emmitting disconnect +43ms
  Able recieved disconnect +7ms
Got a disconnect
Got a disconnect
  bindings      Emmitting disconnect +18ms
  Able recieved disconnect +8ms
Got a disconnect
  Able unknown peripheral 58:9c:ec:e0:01:0d disconnected! +8ms
Able: unknown peripheral 58:9c:ec:e0:01:0d disconnected!
  bindings      Restarting adverstising +19ms
  hci set advertise enable - writing: 010a200101 +10ms
  hci Did someone hear: true +6ms
  hci onSocketData: 040e04010a2000  event type = 4 +9ms
  hci   sub event type = 14 +6ms
  hci       EVT_CMD_COMPLETE +5ms
  hci       cmd = 8202 +5ms
  hci       status = 0 +6ms
  hci       result =  +5ms
  hci       LE_SET_ADVERTISE_ENABLE_CMD +3ms
mak3rm1k3 commented 5 years ago

Did you ever figure this out? I'm just starting out and having the same issue, iOS 12.3.1, node v8.16.1 (node 10.x was having issues with bluetooth-hci-socket), Raspbian 9 stretch on rpi3.