Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

rpi3 + disconnects #27

Open
mdgagne opened this issue Mar 23, 2017 · 6 comments
Open

rpi3 + disconnects #27

mdgagne opened this issue Mar 23, 2017 · 6 comments

Comments

@mdgagne
Copy link

mdgagne commented Mar 23, 2017

Greetings,

I'm using the node-metawear library to collect accelerometer data over BLE and have been running into a consistent disconnect problem using a raspberry pi 3 running the latest raspbian jessie image with updates and the latest build of bluez (5.44) I downloaded and compiled. I've dug around here, on the node-metawear git, and noble git. Posting here seems the most relevant spot because it seems to be a NobleDevice related problem.

Anyhow, I'm running into disconnect problems fairly regularly. Basically, the 'disconnect' event fires sometime between discovery and connectAndSetup completion. My disconnect event callback simply schedule a new discovery/connect 1000ms later using setTimeout; however, when this problem occurs the app never successfully connects to the sensor. I've included an hcidump log capturing the intial discovery and connected attempt followed by roughly 10 seconds of thrashing before the app closes. Please let me know if I can include any additional information.

HCI sniffer - Bluetooth packet analyzer ver 5.23
device: hci0 snap_len: 1500 filter: 0xffffffff
2017-03-22 21:32:43.859630 < HCI Command: Set Event Mask (0x03|0x0001) plen 8
    Mask: 0xfffffbff07f8bf3d
2017-03-22 21:32:43.860118 > HCI Event: Command Complete (0x0e) plen 4
    Set Event Mask (0x03|0x0001) ncmd 1
    status 0x00
2017-03-22 21:32:43.860732 < HCI Command: LE Set Event Mask (0x08|0x0001) plen 8
    mask 0x1f00000000000000 (Reserved)
2017-03-22 21:32:43.861193 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Event Mask (0x08|0x0001) ncmd 1
    status 0x00
2017-03-22 21:32:43.861307 < HCI Command: Read Local Version Information (0x04|0x0001) plen 0
2017-03-22 21:32:43.861796 > HCI Event: Command Complete (0x0e) plen 12
    Read Local Version Information (0x04|0x0001) ncmd 1
    status 0x00
    HCI Version: 4.1 (0x7) HCI Revision: 0xb6
    LMP Version: 4.1 (0x7) LMP Subversion: 0x2209
    Manufacturer: Broadcom Corporation (15)
2017-03-22 21:32:43.861821 < HCI Command: Write LE Host Supported (0x03|0x006d) plen 2
  01 00 
2017-03-22 21:32:43.862219 > HCI Event: Command Complete (0x0e) plen 4
    Write LE Host Supported (0x03|0x006d) ncmd 1
    00 
2017-03-22 21:32:43.862323 < HCI Command: Read LE Host Supported (0x03|0x006c) plen 0
2017-03-22 21:32:43.862699 > HCI Event: Command Complete (0x0e) plen 6
    Read LE Host Supported (0x03|0x006c) ncmd 1
    00 01 00 
2017-03-22 21:32:43.862800 < HCI Command: Read BD ADDR (0x04|0x0009) plen 0
2017-03-22 21:32:43.863217 > HCI Event: Command Complete (0x0e) plen 10
    Read BD ADDR (0x04|0x0009) ncmd 1
    status 0x00 bdaddr B8:27:EB:68:62:DA
2017-03-22 21:32:43.989258 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x00 (scanning disabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:43.989692 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x0c
    Error: Command Disallowed
2017-03-22 21:32:43.989916 < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
    type 0x01 (active)
    interval 10.000ms window 10.000ms
    own address: 0x00 (Public) policy: All
2017-03-22 21:32:43.990420 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Parameters (0x08|0x000b) ncmd 1
    status 0x00
2017-03-22 21:32:43.996589 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x00 (scanning disabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:43.996987 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x0c
    Error: Command Disallowed
2017-03-22 21:32:43.997014 < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
    type 0x01 (active)
    interval 10.000ms window 10.000ms
    own address: 0x00 (Public) policy: All
2017-03-22 21:32:43.997454 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Parameters (0x08|0x000b) ncmd 1
    status 0x00
2017-03-22 21:32:43.997478 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x01 (scanning enabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:43.997944 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x00
2017-03-22 21:32:44.075638 > HCI Event: LE Meta Event (0x3e) plen 43
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr F8:04:2E:E7:73:BD (Public)
      Flags: 0x00
      Unknown type 0xff with 26 bytes data
      RSSI: -50
2017-03-22 21:32:44.088803 > HCI Event: LE Meta Event (0x3e) plen 33
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr 75:C2:E7:72:E2:0C (Random)
      Flags: 0x1a
      Unknown type 0x07 with 16 bytes data
      RSSI: -71
2017-03-22 21:32:44.195711 > HCI Event: LE Meta Event (0x3e) plen 12
    LE Advertising Report
      SCAN_RSP - Scan Response (4)
      bdaddr 75:C2:E7:72:E2:0C (Random)
      RSSI: -86
2017-03-22 21:32:44.200553 > HCI Event: LE Meta Event (0x3e) plen 43
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr E9:D1:C1:68:0D:86 (Random)
      Shortened local name: 'MetaWear'
      Flags: 0x06
      Unknown type 0x06 with 16 bytes data
      RSSI: -75
2017-03-22 21:32:44.200770 > HCI Event: LE Meta Event (0x3e) plen 12
    LE Advertising Report
      SCAN_RSP - Scan Response (4)
      bdaddr E9:D1:C1:68:0D:86 (Random)
      RSSI: -75
2017-03-22 21:32:44.207076 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x00 (scanning disabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:44.209143 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x00
2017-03-22 21:32:44.211708 < HCI Command: LE Create Connection (0x08|0x000d) plen 25
    bdaddr E9:D1:C1:68:0D:86 type 1
    interval 96 window 48 initiator_filter 0
    own_bdaddr_type 0 min_interval 6 max_interval 12
    latency 0 supervision_to 200 min_ce 4 max_ce 6
2017-03-22 21:32:44.212492 > HCI Event: Command Status (0x0f) plen 4
    LE Create Connection (0x08|0x000d) status 0x00 ncmd 1
2017-03-22 21:32:45.053082 > HCI Event: LE Meta Event (0x3e) plen 19
    LE Connection Complete
      status 0x00 handle 64, role master
      bdaddr E9:D1:C1:68:0D:86 (Random)
2017-03-22 21:32:45.053291 < HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2
  40 00 
2017-03-22 21:32:45.054921 > HCI Event: Command Status (0x0f) plen 4
    LE Read Remote Used Features (0x08|0x0016) status 0x00 ncmd 1
2017-03-22 21:32:45.137374 > HCI Event: LE Meta Event (0x3e) plen 12
    LE Read Remote Used Features Complete
      status 0x13 handle 64
      Error: Remote User Terminated Connection
2017-03-22 21:32:45.137961 > HCI Event: Disconn Complete (0x05) plen 4
    status 0x00 handle 64 reason 0x13
    Reason: Remote User Terminated Connection
2017-03-22 21:32:45.244871 < ACL data: handle 64 flags 0x00 dlen 7
    ATT: MTU req (0x02)
      client rx mtu 256
2017-03-22 21:32:45.417203 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
2017-03-22 21:32:46.191944 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x00 (scanning disabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:46.192363 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x0c
    Error: Command Disallowed
2017-03-22 21:32:46.192392 < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
    type 0x01 (active)
    interval 10.000ms window 10.000ms
    own address: 0x00 (Public) policy: All
2017-03-22 21:32:46.192880 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Parameters (0x08|0x000b) ncmd 1
    status 0x00
2017-03-22 21:32:46.192903 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x01 (scanning enabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:46.193314 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x00
2017-03-22 21:32:46.201766 > HCI Event: LE Meta Event (0x3e) plen 43
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr F8:04:2E:E7:73:BD (Public)
      Flags: 0x00
      Unknown type 0xff with 26 bytes data
      RSSI: -46
2017-03-22 21:32:46.216384 > HCI Event: LE Meta Event (0x3e) plen 33
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr 75:C2:E7:72:E2:0C (Random)
      Flags: 0x1a
      Unknown type 0x07 with 16 bytes data
      RSSI: -56
2017-03-22 21:32:46.320490 > HCI Event: LE Meta Event (0x3e) plen 12
    LE Advertising Report
      SCAN_RSP - Scan Response (4)
      bdaddr 75:C2:E7:72:E2:0C (Random)
      RSSI: -83
2017-03-22 21:32:46.966325 > HCI Event: LE Meta Event (0x3e) plen 29
    LE Advertising Report
      SCAN_RSP - Scan Response (4)
      bdaddr F8:04:2E:E7:73:BD (Public)
      Shortened local name: '[TV] UN60JS7000'
      RSSI: -67
2017-03-22 21:32:47.080360 > HCI Event: LE Meta Event (0x3e) plen 27
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr 1C:1A:C0:69:F9:00 (Public)
      Flags: 0x1a
      Unknown type 0xff with 10 bytes data
      RSSI: -81
2017-03-22 21:32:47.257026 > HCI Event: LE Meta Event (0x3e) plen 39
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr F6:0D:BF:1F:57:92 (Random)
      Flags: 0x06
      Unknown type 0x06 with 16 bytes data
      Unknown type 0x16 with 4 bytes data
      RSSI: -94
2017-03-22 21:32:47.263132 > HCI Event: LE Meta Event (0x3e) plen 12
    LE Advertising Report
      SCAN_RSP - Scan Response (4)
      bdaddr 1C:1A:C0:69:F9:00 (Public)
      RSSI: -94
2017-03-22 21:32:47.511798 > HCI Event: LE Meta Event (0x3e) plen 43
    LE Advertising Report
      ADV_IND - Connectable undirected advertising (0)
      bdaddr E9:D1:C1:68:0D:86 (Random)
      Shortened local name: 'MetaWear'
      Flags: 0x06
      Unknown type 0x06 with 16 bytes data
      RSSI: -59
2017-03-22 21:32:48.775608 > HCI Event: LE Meta Event (0x3e) plen 12
    LE Advertising Report
      SCAN_RSP - Scan Response (4)
      bdaddr E9:D1:C1:68:0D:86 (Random)
      RSSI: -84
2017-03-22 21:32:48.779280 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x00 (scanning disabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:48.780431 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x00
2017-03-22 21:32:48.780796 < HCI Command: LE Create Connection (0x08|0x000d) plen 25
    bdaddr E9:D1:C1:68:0D:86 type 1
    interval 96 window 48 initiator_filter 0
    own_bdaddr_type 0 min_interval 6 max_interval 12
    latency 0 supervision_to 200 min_ce 4 max_ce 6
2017-03-22 21:32:48.781640 > HCI Event: Command Status (0x0f) plen 4
    LE Create Connection (0x08|0x000d) status 0x00 ncmd 1
2017-03-22 21:32:53.982540 < HCI Command: Disconnect (0x01|0x0006) plen 3
    handle 0 reason 0x13
    Reason: Remote User Terminated Connection
2017-03-22 21:32:53.983037 > HCI Event: Command Status (0x0f) plen 4
    Disconnect (0x01|0x0006) status 0x02 ncmd 1
    Error: Unknown Connection Identifier
2017-03-22 21:32:53.983652 < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
    value 0x00 (scanning disabled)
    filter duplicates 0x01 (enabled)
2017-03-22 21:32:53.984051 > HCI Event: Command Complete (0x0e) plen 4
    LE Set Scan Enable (0x08|0x000c) ncmd 1
    status 0x0c
    Error: Command Disallowed
2017-03-22 21:32:54.279386 > HCI Event: LE Meta Event (0x3e) plen 19
    LE Connection Complete
      status 0x00 handle 64, role master
      bdaddr E9:D1:C1:68:0D:86 (Random)
2017-03-22 21:32:54.279717 < HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2
  40 00 
2017-03-22 21:32:54.282515 > HCI Event: Command Status (0x0f) plen 4
    LE Read Remote Used Features (0x08|0x0016) status 0x00 ncmd 1
2017-03-22 21:32:54.450029 > HCI Event: LE Meta Event (0x3e) plen 12
    LE Read Remote Used Features Complete
      status 0x00 handle 64
      Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
2017-03-22 21:32:54.475813 < ACL data: handle 64 flags 0x00 dlen 7
    ATT: MTU req (0x02)
      client rx mtu 517
2017-03-22 21:32:54.584864 > ACL data: handle 64 flags 0x02 dlen 7
    ATT: MTU resp (0x03)
      server rx mtu 23
2017-03-22 21:32:54.585056 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Group req (0x10)
      start 0x0001, end 0xffff
      type-uuid 0x2800
2017-03-22 21:32:54.667179 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
2017-03-22 21:32:54.735679 > ACL data: handle 64 flags 0x02 dlen 24
    ATT: Read By Group resp (0x11)
      attr handle 0x0001, end group handle 0x0007
      value 0x00 0x18
      attr handle 0x0008, end group handle 0x000b
      value 0x01 0x18
      attr handle 0x000c, end group handle 0x000f
      value 0x0f 0x18
2017-03-22 21:32:54.735779 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Group req (0x10)
      start 0x0010, end 0xffff
      type-uuid 0x2800
2017-03-22 21:32:54.809920 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:54.854957 > ACL data: handle 64 flags 0x02 dlen 12
    ATT: Read By Group resp (0x11)
      attr handle 0x0010, end group handle 0x001a
      value 0x0a 0x18
2017-03-22 21:32:54.855097 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Group req (0x10)
      start 0x001b, end 0xffff
      type-uuid 0x2800
2017-03-22 21:32:54.915710 > ACL data: handle 64 flags 0x02 dlen 26
    ATT: Read By Group resp (0x11)
      attr handle 0x001b, end group handle 0xffff
      value 0x5a 0xe7 0xba 0xfb 0x4c 0x46 0xdd 0xd9 0x95 0x91 0xcb 0x85 0x00 0x90 0x6a 0x32
2017-03-22 21:32:54.916190 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Group req (0x10)
      start 0x0001, end 0xffff
      type-uuid 0x2801
2017-03-22 21:32:55.019959 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:55.034904 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Group req (0x10) on handle 0x0001
2017-03-22 21:32:55.035037 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0001, end 0x0007
      type-uuid 0x2802
2017-03-22 21:32:55.064903 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x0001
2017-03-22 21:32:55.064990 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0008, end 0x000b
      type-uuid 0x2802
2017-03-22 21:32:55.139978 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:55.214906 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x0008
2017-03-22 21:32:55.214998 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x000c, end 0x000f
      type-uuid 0x2802
2017-03-22 21:32:55.379908 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x000c
2017-03-22 21:32:55.380002 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0010, end 0x001a
      type-uuid 0x2802
2017-03-22 21:32:55.394958 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:55.454927 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x0010
2017-03-22 21:32:55.455015 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x001b, end 0xffff
      type-uuid 0x2802
2017-03-22 21:32:55.530522 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x001b
2017-03-22 21:32:55.530611 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0001, end 0x0007
      type-uuid 0x2803
2017-03-22 21:32:55.604922 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:55.605787 > ACL data: handle 64 flags 0x02 dlen 27
    ATT: Read By Type resp (0x09)
      length: 7
        handle 0x0002, value 0x0a 0x03 0x00 0x00 0x2a 
        handle 0x0004, value 0x02 0x05 0x00 0x01 0x2a 
        handle 0x0006, value 0x02 0x07 0x00 0x04 0x2a 
2017-03-22 21:32:55.605872 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0007, end 0x0007
      type-uuid 0x2803
2017-03-22 21:32:55.709908 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x0007
2017-03-22 21:32:55.710038 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0008, end 0x000b
      type-uuid 0x2803
2017-03-22 21:32:55.844968 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:55.934984 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Read By Type resp (0x09)
      length: 7
        handle 0x0009, value 0x20 0x0a 0x00 0x05 0x2a 
2017-03-22 21:32:55.935121 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x000a, end 0x000b
      type-uuid 0x2803
2017-03-22 21:32:56.009909 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x000a
2017-03-22 21:32:56.010025 < ACL data: handle 64 flags 0x00 dlen 9
    ATT: Find Information req (0x04)
      start 0x000b, end 0x000b
2017-03-22 21:32:56.144909 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:56.145537 > ACL data: handle 64 flags 0x02 dlen 10
    ATT: Find Information resp (0x05)
      format: uuid-16
        handle 0x000b, uuid 0x2902 (GATT(desc) Client Characteristic Configuration)
2017-03-22 21:32:56.145668 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x000c, end 0x000f
      type-uuid 0x2803
2017-03-22 21:32:56.249985 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Read By Type resp (0x09)
      length: 7
        handle 0x000d, value 0x12 0x0e 0x00 0x19 0x2a 
2017-03-22 21:32:56.250127 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x000e, end 0x000f
      type-uuid 0x2803
2017-03-22 21:32:56.339963 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:56.369909 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x000e
2017-03-22 21:32:56.370026 < ACL data: handle 64 flags 0x00 dlen 9
    ATT: Find Information req (0x04)
      start 0x000f, end 0x000f
2017-03-22 21:32:56.519929 > ACL data: handle 64 flags 0x02 dlen 10
    ATT: Find Information resp (0x05)
      format: uuid-16
        handle 0x000f, uuid 0x2902 (GATT(desc) Client Characteristic Configuration)
2017-03-22 21:32:56.520044 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0010, end 0x001a
      type-uuid 0x2803
2017-03-22 21:32:56.534983 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:56.625694 > ACL data: handle 64 flags 0x02 dlen 27
    ATT: Read By Type resp (0x09)
      length: 7
        handle 0x0011, value 0x02 0x12 0x00 0x29 0x2a 
        handle 0x0013, value 0x02 0x14 0x00 0x24 0x2a 
        handle 0x0015, value 0x02 0x16 0x00 0x25 0x2a 
2017-03-22 21:32:56.625880 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x0016, end 0x001a
      type-uuid 0x2803
2017-03-22 21:32:56.715148 > ACL data: handle 64 flags 0x02 dlen 20
    ATT: Read By Type resp (0x09)
      length: 7
        handle 0x0017, value 0x02 0x18 0x00 0x27 0x2a 
        handle 0x0019, value 0x02 0x1a 0x00 0x26 0x2a 
2017-03-22 21:32:56.715314 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x001a, end 0x001a
      type-uuid 0x2803
2017-03-22 21:32:56.774983 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:56.864923 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x001a
2017-03-22 21:32:56.865220 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x001b, end 0xffff
      type-uuid 0x2803
2017-03-22 21:32:56.955696 > ACL data: handle 64 flags 0x02 dlen 27
    ATT: Read By Type resp (0x09)
      length: 21
        handle 0x001c, value 0x0e 0x1d 0x00 0x5a 0xe7 0xba 0xfb 0x4c 0x46 0xdd 0xd9 0x95 0x91 0xcb 0x85 0x01 0x90 0x6a 0x32 
2017-03-22 21:32:56.955867 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x001d, end 0xffff
      type-uuid 0x2803
2017-03-22 21:32:57.030000 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:57.105698 > ACL data: handle 64 flags 0x02 dlen 27
    ATT: Read By Type resp (0x09)
      length: 21
        handle 0x001e, value 0x12 0x1f 0x00 0x5a 0xe7 0xba 0xfb 0x4c 0x46 0xdd 0xd9 0x95 0x91 0xcb 0x85 0x06 0x90 0x6a 0x32 
2017-03-22 21:32:57.105890 < ACL data: handle 64 flags 0x00 dlen 11
    ATT: Read By Type req (0x08)
      start 0x001f, end 0xffff
      type-uuid 0x2803
2017-03-22 21:32:57.134924 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Read By Type req (0x08) on handle 0x001f
2017-03-22 21:32:57.135153 < ACL data: handle 64 flags 0x00 dlen 9
    ATT: Find Information req (0x04)
      start 0x0020, end 0xffff
2017-03-22 21:32:57.209984 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:57.239945 > ACL data: handle 64 flags 0x02 dlen 10
    ATT: Find Information resp (0x05)
      format: uuid-16
        handle 0x0020, uuid 0x2902 (GATT(desc) Client Characteristic Configuration)
2017-03-22 21:32:57.240113 < ACL data: handle 64 flags 0x00 dlen 9
    ATT: Find Information req (0x04)
      start 0x0021, end 0xffff
2017-03-22 21:32:57.359927 > ACL data: handle 64 flags 0x02 dlen 9
    ATT: Error (0x01)
      Error: Attribute not found (10)
      Find Information req (0x04) on handle 0x0021
2017-03-22 21:32:57.375516 < ACL data: handle 64 flags 0x00 dlen 9
    ATT: Write req (0x12)
      handle 0x000b value  0x02 0x00
2017-03-22 21:32:57.480015 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 2
2017-03-22 21:32:57.539850 > ACL data: handle 64 flags 0x02 dlen 5
    ATT: Write resp (0x13)
2017-03-22 21:32:57.540113 < ACL data: handle 64 flags 0x00 dlen 7
    ATT: Read req (0x0a)
      handle 0x0003
2017-03-22 21:32:57.779992 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Read resp (0x0b)
      4D 65 74 61 57 65 61 72 
2017-03-22 21:32:57.780330 < ACL data: handle 64 flags 0x00 dlen 7
    ATT: Read req (0x0a)
      handle 0x0005
2017-03-22 21:32:57.917233 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
2017-03-22 21:32:57.930513 > ACL data: handle 64 flags 0x02 dlen 7
    ATT: Read resp (0x0b)
      80 01 
2017-03-22 21:32:58.167532 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
@sandeepmistry
Copy link
Collaborator

This is related to noble/noble#480

@mdgagne
Copy link
Author

mdgagne commented Apr 22, 2017 •
edited
Loading

@sandeepmistry
Thanks for you reply. I read through the post and tested the modification that you made to the connection parameters; however, I'm still running into this problem. I've also attempted adding reconnect logic. Once this occurs (about 50-75% of the time) I have to restart the node app.

Could you explain the problem to me? Is there any additional information I could provide to help with a fix?

@sandeepmistry
Copy link
Collaborator

The kernel is sending out a disconnect message based on some timing conditions

2017-03-22 21:32:53.982540 < HCI Command: Disconnect (0x01|0x0006) plen 3
    handle 0 reason 0x13
    Reason: Remote User Terminated Connection

@mdgagne
Copy link
Author

mdgagne commented Apr 30, 2017

@sandeepmistry
Thanks for pointing out the specific issues from the hci dump for me. I can reproduce this intermittently with gatttool so it may be an error with the devices. In this scenario when my node app reconnects hcidump shows a successful reconnect; however, I don't receive any of the events that I expect from the noble device. How should I be attempting reconnect?

@sandeepmistry
Copy link
Collaborator

@mdgagne

I can reproduce this intermittently with gatttool so it may be an error with the devices.

Maybe we should close then?

How should I be attempting reconnect?

What does your current code look like?

@mdgagne
Copy link
Author

mdgagne commented May 13, 2017

@sandeepmistry
Even if there is an issue with the device, I dont think that disconnect (at any time) should prevent noble from being able to reconnect. Here is an modified example node-metawear example that reproduces the problem. I added some simple reconnect logic that attempts to reconnect anytime a connection is lost. This example assumes only 1 metawear device is in range.

var devices = require('node-metawear');

var rate  = parseFloat(process.argv[2]) || 50;
var range = parseFloat(process.argv[3]) || 2;
var connected =false;

function makeConnection () {
	if (connected) {
		console.log ("already connected");
	}
	
	console.log ("not connected, connecting");
	devices.discover(function(device) {
		console.log('discovered device ', device.address);

		device.on('disconnect', function() {
			console.log('we got disconnected! :( ');
			connected = false;
		});

		device.connectAndSetup(function(error) {
			connected = true;
			console.log('were connected!');
			console.log('Start accelerometer with ' + rate + 'hz ang +-' + range + 'g');

			var accelerometer = new device.Accelerometer(device);
			var logger        = new device.Log(device);

			accelerometer.setOutputDataRate(rate);
			accelerometer.setAxisSamplingRange(range);
			logger.startLogging(false);

			accelerometer.setConfig();
			accelerometer.enableNotifications();
			accelerometer.enableAxisSampling();
			accelerometer.start();

			accelerometer.onChange(function(data) {
				console.log("x:", data.x, "\t\ty:", data.y, "\t\tz:", data.z);
			});
		});
	});
}

makeConnection ();
setInterval (makeConnection, 10000);

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@mdgagne @sandeepmistry