All of lore.kernel.org
 help / color / mirror / Atom feed
* Disabled bluetooth cache. But the app still getting wrong data?
@ 2021-04-13  5:59 Kenny Bian
  2021-04-13  6:39 ` Jamie Mccrae
  0 siblings, 1 reply; 13+ messages in thread
From: Kenny Bian @ 2021-04-13  5:59 UTC (permalink / raw)
  To: linux-bluetooth

[-- Attachment #1: Type: text/plain, Size: 2043 bytes --]

Previously we had an issue: if there is a change of characteristics in
the new build of our firmware, then the app will get the wrong data.
By saying changed characteristics, it can be an added or removed
characteristic, or adding notification to an existing characteristic.
In order to keep the pairing information, the "/var/lib/bluetooth"
folder is copied over to the new build's partition. We realized that
there is no "service changed indication". The app can't handle the
changed services. So we disabled the bluetooth cache by set this in
"/etc/bluetooth/main.conf":
[GATT]
Cache = no

But recently, we saw the problem again even if the bluetooth cache is
disabled: in the build number 101, a characteristic is removed. But
when we upgrade the build from 100 to 101, the app gets the wrong
data. We looked at the log. When the app tries to read temperature by
using the temperature UUID, somehow the bluetooth service we created
received the request to read the "device name"(device name UUID). So
the "device name" is returned to the app as the temperature. This
looks like the same behavior as the bluetooth cache is not disabled. I
looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no
"[Attributes]" section in the files in the folder. That means the
disabled cache seems working.

The only way to fix this issue is to force exit the mobile app on the
phone and "Forget This Device" in iOS or "Unpair" in Android.

I looked at the btmon(see attached). For the working btmon log, there
is "Attribute group list: XX entries" under "ACL Data TX". But there
is no "Attribute group list: XX entries" under "ACL Data TX" in the
attached problematic btmon log.

Questions:
1. How is it possible that this still happens even if the bluetooth
cache is disabled?
2. Is this the problem on the Linux side which runs the GATT server or
on the mobile side?
3. Is there anything else we should look into?

We're going to release our product soon. This is a critical issue for
us. Please help if you have any suggestions.

Thanks!

[-- Attachment #2: btmon_ios_wrongdata.log --]
[-- Type: application/octet-stream, Size: 98304 bytes --]

Bluetooth monitor ver 5.48
= Note: Linux version 4.19.35-g4e7ddffd720 (armv7l)                    0.539517
= Note: Bluetooth subsystem version 2.22                               0.539532
= New Index: 00:16:A4:5B:4F:02 (Primary,UART,hci0)              [hci0] 0.539537
= Open Index: 00:16:A4:5B:4F:02                                 [hci0] 0.539541
= Index Info: 00:16:A4:5.. (Cypress Semiconductor Corporation)  [hci0] 0.539544
@ MGMT Open: bluetoothd (privileged) version 1.14             {0x0002} 0.539549
@ MGMT Open: bluetoothd (privileged) version 1.14             {0x0001} 0.539552
@ MGMT Open: btmon (privileged) version 1.14                  {0x0003} 0.539625
< HCI Command: LE Set Advertising D.. (0x08|0x0008) plen 32  #1 [hci0] 1.687732
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4                  #2 [hci0] 1.690438
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Enable (0x08|0x000a) plen 1  #3 [hci0] 1.690553
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                  #4 [hci0] 1.692488
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising P.. (0x08|0x0006) plen 15  #5 [hci0] 1.692591
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                  #6 [hci0] 1.698081
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Enable (0x08|0x000a) plen 1  #7 [hci0] 1.698180
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                  #8 [hci0] 1.699297
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising D.. (0x08|0x0008) plen 32  #9 [hci0] 3.767747
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4                 #10 [hci0] 3.769253
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Ena.. (0x08|0x000a) plen 1  #11 [hci0] 3.769359
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                 #12 [hci0] 3.770871
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising... (0x08|0x0006) plen 15  #13 [hci0] 3.770971
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                 #14 [hci0] 3.773388
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Ena.. (0x08|0x000a) plen 1  #15 [hci0] 3.773494
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                 #16 [hci0] 3.774888
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising... (0x08|0x0008) plen 32  #17 [hci0] 5.847528
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4                 #18 [hci0] 5.851890
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Ena.. (0x08|0x000a) plen 1  #19 [hci0] 5.852133
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                 #20 [hci0] 5.858188
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising... (0x08|0x0006) plen 15  #21 [hci0] 5.858404
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                 #22 [hci0] 5.860285
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Ena.. (0x08|0x000a) plen 1  #23 [hci0] 5.860512
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                 #24 [hci0] 5.862384
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising... (0x08|0x0008) plen 32  #25 [hci0] 7.927261
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4                 #26 [hci0] 7.929157
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Ena.. (0x08|0x000a) plen 1  #27 [hci0] 7.929241
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                 #28 [hci0] 7.930777
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising... (0x08|0x0006) plen 15  #29 [hci0] 7.930857
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                 #30 [hci0] 7.933341
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Ena.. (0x08|0x000a) plen 1  #31 [hci0] 7.933432
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                 #32 [hci0] 7.934877
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising.. (0x08|0x0008) plen 32  #33 [hci0] 10.007307
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4                #34 [hci0] 10.009298
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise En.. (0x08|0x000a) plen 1  #35 [hci0] 10.009403
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                #36 [hci0] 10.011149
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising.. (0x08|0x0006) plen 15  #37 [hci0] 10.011255
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                #38 [hci0] 10.016829
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise En.. (0x08|0x000a) plen 1  #39 [hci0] 10.016929
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                #40 [hci0] 10.018045
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising.. (0x08|0x0008) plen 32  #41 [hci0] 12.087988
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4                #42 [hci0] 12.089688
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise En.. (0x08|0x000a) plen 1  #43 [hci0] 12.089794
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4                #44 [hci0] 12.091943
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertising.. (0x08|0x0006) plen 15  #45 [hci0] 12.092051
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                #46 [hci0] 12.098073
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise En.. (0x08|0x000a) plen 1  #47 [hci0] 12.098178
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                #48 [hci0] 12.099471
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19                  #49 [hci0] 12.105968
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 64
        Role: Slave (0x01)
        Peer address type: Random (0x01)
        Peer address: 66:42:DF:2C:C7:48 (Resolvable)
        Connection interval: 30.00 msec (0x0018)
        Connection latency: 0 (0x0000)
        Supervision timeout: 720 msec (0x0048)
        Master clock accuracy: 0x05
@ MGMT Event: Device Connected (0x000b) plen 13       {0x0003} [hci0] 12.106092
        LE Address: 6C:96:CF:98:99:12 (Apple, Inc.)
        Flags: 0x00000000
        Data length: 0
@ MGMT Event: Device Connected (0x000b) plen 13       {0x0002} [hci0] 12.106092
        LE Address: 6C:96:CF:98:99:12 (Apple, Inc.)
        Flags: 0x00000000
        Data length: 0
@ MGMT Event: Device Connected (0x000b) plen 13       {0x0001} [hci0] 12.106092
        LE Address: 6C:96:CF:98:99:12 (Apple, Inc.)
        Flags: 0x00000000
        Data length: 0
< HCI Command: LE Read Remote Used.. (0x08|0x0016) plen 2  #50 [hci0] 12.106419
        Handle: 64
> HCI Event: Command Status (0x0f) plen 4                  #51 [hci0] 12.125657
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 13                  #52 [hci0] 12.280095
      LE Long Term Key Request (0x05)
        Handle: 64
        Random number: 0x0000000000000000
        Encrypted diversifier: 0x0000
< HCI Command: LE Long Term Key R.. (0x08|0x001a) plen 18  #53 [hci0] 12.280195
        Handle: 64
        Long term key: 6bd03e98a5caaf183fac20180e3ad49e
> HCI Event: Command Complete (0x0e) plen 6                #54 [hci0] 12.283639
      LE Long Term Key Request Reply (0x08|0x001a) ncmd 1
        Status: Success (0x00)
        Handle: 64
> HCI Event: Encryption Change (0x08) plen 4               #55 [hci0] 12.400577
        Status: Success (0x00)
        Handle: 64
        Encryption: Enabled with AES-CCM (0x01)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                 #56 [hci0] 12.415480
      ATT: Exchange MTU Request (0x02) len 2
        Client RX MTU: 517
> HCI Event: LE Meta Event (0x3e) plen 12                  #57 [hci0] 12.460549
      LE Read Remote Used Features (0x04)
        Status: Success (0x00)
        Handle: 64
        Features: 0x1d 0x00 0x00 0x00 0x00 0x00 0x00 0x00
          LE Encryption
          Extended Reject Indication
          Slave-initiated Features Exchange
          LE Ping
> ACL Data RX: Handle 64 flags 0x02 dlen 11                #58 [hci0] 12.610121
      ATT: Handle Value Indication (0x1d) len 6
        Handle: 0x0008
          Data: 0a00ffff
< ACL Data TX: Handle 64 flags 0x00 dlen 5                 #59 [hci0] 12.610830
      ATT: Handle Value Confirmation (0x1e) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 7                 #60 [hci0] 12.611041
      ATT: Exchange MTU Response (0x03) len 2
        Server RX MTU: 185
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #61 [hci0] 12.611639
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
> ACL Data RX: Handle 64 flags 0x02 dlen 9                 #62 [hci0] 12.640897
      ATT: Write Request (0x12) len 4
        Handle: 0x0009
          Data: 0200
< ACL Data TX: Handle 64 flags 0x00 dlen 5                 #63 [hci0] 12.641724
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5     #64 [hci0] 12.670336
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 18                #65 [hci0] 12.730673
      ATT: Read By Group Type Response (0x11) len 13
        Attribute data length: 6
        Attribute group list: 2 entries
        Handle range: 0x0001-0x0005
        UUID: Generic Access Profile (0x1800)
        Handle range: 0x0006-0x0009
        UUID: Generic Attribute Profile (0x1801)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #66 [hci0] 12.731201
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x000a-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5     #67 [hci0] 12.733753
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 27                #68 [hci0] 12.790340
> ACL Data RX: Handle 64 flags 0x01 dlen 19                #69 [hci0] 12.790947
      ATT: Read By Group Type Response (0x11) len 41
        Attribute data length: 20
        Attribute group list: 2 entries
        Handle range: 0x000a-0x000e
        UUID: Vendor specific (d0611e78-bbb4-4591-a5f8-487910ae4366)
        Handle range: 0x000f-0x0013
        UUID: Vendor specific (9fa480e0-4967-4542-9390-d343dc5d04ae)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #70 [hci0] 12.791409
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0014-0xffff
        Attribute group type: Primary Service (0x2800)
> ACL Data RX: Handle 64 flags 0x02 dlen 24                #71 [hci0] 12.850549
      ATT: Read By Group Type Response (0x11) len 19
        Attribute data length: 6
        Attribute group list: 3 entries
        Handle range: 0x0014-0x0017
        UUID: Battery Service (0x180f)
        Handle range: 0x0018-0x001d
        UUID: Current Time Service (0x1805)
        Handle range: 0x001e-0x0022
        UUID: Device Information (0x180a)
> HCI Event: Number of Completed Packets (0x13) plen 5     #72 [hci0] 12.850818
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #73 [hci0] 12.858107
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0023-0xffff
        Attribute group type: Primary Service (0x2800)
> ACL Data RX: Handle 64 flags 0x02 dlen 27                #74 [hci0] 12.910604
> ACL Data RX: Handle 64 flags 0x01 dlen 19                #75 [hci0] 12.910937
      ATT: Read By Group Type Response (0x11) len 41
        Attribute data length: 20
        Attribute group list: 2 entries
        Handle range: 0x0023-0x002c
        UUID: Vendor specific (7905f431-b5ce-4e99-a40f-4b1e122d00d0)
        Handle range: 0x002d-0x0038
        UUID: Vendor specific (89d3502b-0f36-433a-8ef4-c502ad55f8dc)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #76 [hci0] 12.911380
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0039-0xffff
        Attribute group type: Primary Service (0x2800)
> ACL Data RX: Handle 64 flags 0x02 dlen 9                 #77 [hci0] 12.970132
      ATT: Error Response (0x01) len 4
        Read By Group Type Request (0x10)
        Handle: 0x0039
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #78 [hci0] 12.971068
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Secondary Service (0x2801)
> HCI Event: Number of Completed Packets (0x13) plen 5     #79 [hci0] 12.971278
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 13                #80 [hci0] 13.032011
      ATT: Write Request (0x12) len 8
        Handle: 0x000c
          Data: 303030303030
> ACL Data RX: Handle 64 flags 0x02 dlen 9                 #81 [hci0] 13.059935
      ATT: Error Response (0x01) len 4
        Read By Group Type Request (0x10)
        Handle: 0x0038
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #82 [hci0] 13.060835
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0x0038
        Attribute type: Include (0x2802)
< ACL Data TX: Handle 64 flags 0x00 dlen 5                 #83 [hci0] 13.091418
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                 #84 [hci0] 13.120225
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0038
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #85 [hci0] 13.120972
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0x0038
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5     #86 [hci0] 13.121185
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                 #87 [hci0] 13.149846
      ATT: Read Request (0x0a) len 2
        Handle: 0x0012
< ACL Data TX: Handle 64 flags 0x00 dlen 8                 #88 [hci0] 13.172380
      ATT: Read Response (0x0b) len 3
        Value: 313032
> ACL Data RX: Handle 64 flags 0x02 dlen 27                #89 [hci0] 13.180395
      ATT: Read By Type Response (0x09) len 22
        Attribute data length: 7
        Attribute data list: 3 entries
        Handle: 0x0002
        Value: 020300002a
        Handle: 0x0004
        Value: 020500012a
        Handle: 0x0007
        Value: 200800052a
> HCI Event: Number of Completed Packets (0x13) plen 5     #90 [hci0] 13.180535
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #91 [hci0] 13.181442
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0008-0x0038
        Attribute type: Characteristic (0x2803)
> ACL Data RX: Handle 64 flags 0x02 dlen 13                #92 [hci0] 13.209979
      ATT: Write Request (0x12) len 8
        Handle: 0x000c
          Data: 323232323232
> ACL Data RX: Handle 64 flags 0x02 dlen 27                #93 [hci0] 13.240482
> HCI Event: Number of Completed Packets (0x13) plen 5     #94 [hci0] 13.240742
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x01 dlen 21                #95 [hci0] 13.241025
      ATT: Read By Type Response (0x09) len 43
        Attribute data length: 21
        Attribute data list: 2 entries
        Handle: 0x000b
        Value: 980c004900d927ee54ed84914c379a6c556786
        Handle: 0x0010
        Value: 981100cce349c57ba77a91cd43995bb1ad0baf
< ACL Data TX: Handle 64 flags 0x00 dlen 11                #96 [hci0] 13.241694
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0011-0x0038
        Attribute type: Characteristic (0x2803)
< ACL Data TX: Handle 64 flags 0x00 dlen 5                 #97 [hci0] 13.252205
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 27                #98 [hci0] 13.330457
> HCI Event: Number of Completed Packets (0x13) plen 5     #99 [hci0] 13.330771
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x01 dlen 14               #100 [hci0] 13.330882
      ATT: Read By Type Response (0x09) len 36
        Attribute data length: 7
        Attribute data list: 5 entries
        Handle: 0x0015
        Value: 121600192a
        Handle: 0x0019
        Value: 121a002b2a
        Handle: 0x001c
        Value: 021d000f2a
        Handle: 0x001f
        Value: 022000292a
        Handle: 0x0021
        Value: 022200242a
< ACL Data TX: Handle 64 flags 0x00 dlen 11               #101 [hci0] 13.331358
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0022-0x0038
        Attribute type: Characteristic (0x2803)
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #102 [hci0] 13.331535
      ATT: Read Request (0x0a) len 2
        Handle: 0x0012
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #103 [hci0] 13.362546
      ATT: Read Response (0x0b) len 1
        Value: 30
> ACL Data RX: Handle 64 flags 0x02 dlen 27               #104 [hci0] 13.390337
> ACL Data RX: Handle 64 flags 0x01 dlen 27               #105 [hci0] 13.391226
> HCI Event: Number of Completed Packets (0x13) plen 5    #106 [hci0] 13.391452
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x01 dlen 27               #107 [hci0] 13.391724
> ACL Data RX: Handle 64 flags 0x01 dlen 27               #108 [hci0] 13.392488
> ACL Data RX: Handle 64 flags 0x01 dlen 24               #109 [hci0] 13.393265
      ATT: Read By Type Response (0x09) len 127
        Attribute data length: 21
        Attribute data list: 6 entries
        Handle: 0x0024
        Value: 882500d9d9aafdbd9b2198a849e145f3d8d169
        Handle: 0x0027
        Value: 102800bd1da299e625588cd94201630d12bf9f
        Handle: 0x002a
        Value: 102b00fb7b7cce6ab344beb54bd624e9c6ea22
        Handle: 0x002e
        Value: 982f00c251caf7560edfb88a4ab157d8813c9b
        Handle: 0x0032
        Value: 98330002c196ba92bb0c9a1f418d80ceab7c2f
        Handle: 0x0036
        Value: 8a3700d7d5bb70a8a3aba6d846ab238cf3b2c6
< ACL Data TX: Handle 64 flags 0x00 dlen 11               #110 [hci0] 13.394590
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0037-0x0038
        Attribute type: Characteristic (0x2803)
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #111 [hci0] 13.450535
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0038
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #112 [hci0] 13.451548
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0009-0x0009
> ACL Data RX: Handle 64 flags 0x02 dlen 10               #113 [hci0] 13.540721
      ATT: Find Information Response (0x05) len 5
        Format: UUID-16 (0x01)
        Handle: 0x0009
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #114 [hci0] 13.542566
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x000d-0x000e
> HCI Event: Number of Completed Packets (0x13) plen 5    #115 [hci0] 13.543002
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 14               #116 [hci0] 13.600596
      ATT: Find Information Response (0x05) len 9
        Format: UUID-16 (0x01)
        Handle: 0x000d
        UUID: Characteristic Extended Properties (0x2900)
        Handle: 0x000e
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #117 [hci0] 13.601346
      ATT: Read Request (0x0a) len 2
        Handle: 0x000d
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #118 [hci0] 13.660570
      ATT: Read Response (0x0b) len 2
        Value: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #119 [hci0] 13.661479
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0012-0x0013
> HCI Event: Number of Completed Packets (0x13) plen 5    #120 [hci0] 13.661691
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 14               #121 [hci0] 13.720917
      ATT: Find Information Response (0x05) len 9
        Format: UUID-16 (0x01)
        Handle: 0x0012
        UUID: Characteristic Extended Properties (0x2900)
        Handle: 0x0013
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #122 [hci0] 13.721681
      ATT: Read Request (0x0a) len 2
        Handle: 0x0012
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #123 [hci0] 13.780897
      ATT: Read Response (0x0b) len 2
        Value: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #124 [hci0] 13.781621
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0017-0x0017
> HCI Event: Number of Completed Packets (0x13) plen 5    #125 [hci0] 13.781812
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 10               #126 [hci0] 13.840592
      ATT: Find Information Response (0x05) len 5
        Format: UUID-16 (0x01)
        Handle: 0x0017
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #127 [hci0] 13.841487
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x001b-0x001b
> ACL Data RX: Handle 64 flags 0x02 dlen 10               #128 [hci0] 13.899972
      ATT: Find Information Response (0x05) len 5
        Format: UUID-16 (0x01)
        Handle: 0x001b
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #129 [hci0] 13.900791
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0026-0x0026
> HCI Event: Number of Completed Packets (0x13) plen 5    #130 [hci0] 13.901007
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #131 [hci0] 13.901101
      ATT: Write Request (0x12) len 3
        Handle: 0x0068
          Data: 30
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #132 [hci0] 13.950240
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 10               #133 [hci0] 13.960430
      ATT: Find Information Response (0x05) len 5
        Format: UUID-16 (0x01)
        Handle: 0x0026
        UUID: Characteristic Extended Properties (0x2900)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #134 [hci0] 13.961254
      ATT: Read Request (0x0a) len 2
        Handle: 0x0026
> HCI Event: Number of Completed Packets (0x13) plen 5    #135 [hci0] 13.989790
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #136 [hci0] 14.020535
      ATT: Read Response (0x0b) len 2
        Value: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #137 [hci0] 14.021226
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0029-0x0029
> ACL Data RX: Handle 64 flags 0x02 dlen 10               #138 [hci0] 14.080581
      ATT: Find Information Response (0x05) len 5
        Format: UUID-16 (0x01)
        Handle: 0x0029
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #139 [hci0] 14.081388
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x002c-0x002c
> HCI Event: Number of Completed Packets (0x13) plen 5    #140 [hci0] 14.081603
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #141 [hci0] 14.109826
      ATT: Write Request (0x12) len 3
        Handle: 0x0064
          Data: 32
> ACL Data RX: Handle 64 flags 0x02 dlen 10               #142 [hci0] 14.140992
      ATT: Find Information Response (0x05) len 5
        Format: UUID-16 (0x01)
        Handle: 0x002c
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #143 [hci0] 14.141972
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0030-0x0031
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #144 [hci0] 14.158781
      ATT: Write Response (0x13) len 0
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #145 [hci0] 14.167270
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #146 [hci0] 14.168753
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #147 [hci0] 14.168863
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #148 [hci0] 14.169724
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #149 [hci0] 14.169809
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #150 [hci0] 14.171111
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5    #151 [hci0] 14.200359
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 14               #152 [hci0] 14.230245
      ATT: Find Information Response (0x05) len 9
        Format: UUID-16 (0x01)
        Handle: 0x0030
        UUID: Characteristic Extended Properties (0x2900)
        Handle: 0x0031
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #153 [hci0] 14.231427
      ATT: Read Request (0x0a) len 2
        Handle: 0x0030
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #154 [hci0] 14.231649
      ATT: Write Request (0x12) len 3
        Handle: 0x00ab
          Data: 30
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #155 [hci0] 14.290565
      ATT: Read Response (0x0b) len 2
        Value: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #156 [hci0] 14.291355
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0034-0x0035
> HCI Event: Number of Completed Packets (0x13) plen 5    #157 [hci0] 14.291774
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #158 [hci0] 14.296487
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 14               #159 [hci0] 14.350899
      ATT: Find Information Response (0x05) len 9
        Format: UUID-16 (0x01)
        Handle: 0x0034
        UUID: Characteristic Extended Properties (0x2900)
        Handle: 0x0035
        UUID: Client Characteristic Configuration (0x2902)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #160 [hci0] 14.351725
      ATT: Read Request (0x0a) len 2
        Handle: 0x0034
> HCI Event: Number of Completed Packets (0x13) plen 5    #161 [hci0] 14.358991
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #162 [hci0] 14.359161
      ATT: Write Request (0x12) len 3
        Handle: 0x00a4
          Data: 33
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #163 [hci0] 14.411208
      ATT: Read Response (0x0b) len 2
        Value: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #164 [hci0] 14.411986
      ATT: Find Information Request (0x04) len 4
        Handle range: 0x0038-0x0038
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #165 [hci0] 14.425303
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #166 [hci0] 14.440442
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 10               #167 [hci0] 14.470775
      ATT: Find Information Response (0x05) len 5
        Format: UUID-16 (0x01)
        Handle: 0x0038
        UUID: Characteristic Extended Properties (0x2900)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #168 [hci0] 14.471674
      ATT: Read Request (0x0a) len 2
        Handle: 0x0038
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #169 [hci0] 14.530525
      ATT: Read Response (0x0b) len 2
        Value: 0100
> HCI Event: Number of Completed Packets (0x13) plen 5    #170 [hci0] 14.540217
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #171 [hci0] 14.585138
      ATT: Write Request (0x12) len 4
        Handle: 0x0009
          Data: 0200
> ACL Data RX: Handle 64 flags 0x02 dlen 5                #172 [hci0] 14.649938
      ATT: Write Response (0x13) len 0
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #173 [hci0] 14.713061
      ATT: Read Request (0x0a) len 2
        Handle: 0x0003
> ACL Data RX: Handle 64 flags 0x02 dlen 11               #174 [hci0] 14.800632
      ATT: Read Response (0x0b) len 6
        Value: 50686f6e6558
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #175 [hci0] 14.801370
      ATT: Read Request (0x0a) len 2
        Handle: 0x0005
> HCI Event: Number of Completed Packets (0x13) plen 5    #176 [hci0] 14.801588
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #177 [hci0] 14.860782
      ATT: Read Response (0x0b) len 2
        Value: 4000
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #178 [hci0] 14.861458
      ATT: Read Request (0x0a) len 2
        Handle: 0x0016
> ACL Data RX: Handle 64 flags 0x02 dlen 6                #179 [hci0] 14.920947
      ATT: Read Response (0x0b) len 1
        Value: 55
> HCI Event: Number of Completed Packets (0x13) plen 5    #180 [hci0] 14.921061
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #181 [hci0] 14.921771
      ATT: Write Request (0x12) len 4
        Handle: 0x0017
          Data: 0100
> ACL Data RX: Handle 64 flags 0x02 dlen 5                #182 [hci0] 14.979901
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #183 [hci0] 15.177792
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 11               #184 [hci0] 15.849862
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0x0005
        Attribute type: Device Name (0x2a00)
< ACL Data TX: Handle 64 flags 0x00 dlen 33               #185 [hci0] 15.850919
      ATT: Read By Type Response (0x09) len 28
        Attribute data length: 27
        Attribute data list: 1 entry
        Handle: 0x0003
        Value: 224f332d485542322d3278502d3132313431342f3030303722
> HCI Event: Number of Completed Packets (0x13) plen 5    #186 [hci0] 16.052874
        Num handles: 1
        Handle: 64
        Count: 1
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #187 [hci0] 16.247486
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #188 [hci0] 16.248962
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #189 [hci0] 16.249099
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #190 [hci0] 16.251040
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #191 [hci0] 16.251221
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #192 [hci0] 16.257303
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #193 [hci0] 16.257405
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #194 [hci0] 16.258507
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #195 [hci0] 17.289822
      ATT: Write Request (0x12) len 3
        Handle: 0x0068
          Data: 31
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #196 [hci0] 17.375657
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #197 [hci0] 17.554556
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #198 [hci0] 18.009776
      ATT: Read Request (0x0a) len 2
        Handle: 0x00af
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #199 [hci0] 18.033037
      ATT: Read Response (0x0b) len 1
        Value: 43
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #200 [hci0] 18.070710
      ATT: Write Request (0x12) len 3
        Handle: 0x0064
          Data: 32
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #201 [hci0] 18.106996
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #202 [hci0] 18.159987
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #203 [hci0] 18.315121
      ATT: Read Request (0x0a) len 2
        Handle: 0x00b2
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #204 [hci0] 18.327301
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #205 [hci0] 18.328507
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #206 [hci0] 18.328609
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #207 [hci0] 18.330378
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #208 [hci0] 18.330480
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #209 [hci0] 18.336300
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #210 [hci0] 18.336408
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #211 [hci0] 18.337156
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #212 [hci0] 18.357958
      ATT: Read Response (0x0b) len 2
        Value: 6c78
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #213 [hci0] 18.400613
      ATT: Write Request (0x12) len 3
        Handle: 0x00ab
          Data: 31
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #214 [hci0] 18.480179
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #215 [hci0] 18.519811
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #216 [hci0] 18.640975
      ATT: Read Request (0x0a) len 2
        Handle: 0x00cd
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #217 [hci0] 18.664366
      ATT: Read Response (0x0b) len 4
        Value: 44484350
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #218 [hci0] 18.700470
      ATT: Write Request (0x12) len 3
        Handle: 0x00a4
          Data: 30
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #219 [hci0] 18.739069
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #220 [hci0] 18.789830
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #221 [hci0] 18.999779
      ATT: Read Request (0x0a) len 2
        Handle: 0x00bb
< ACL Data TX: Handle 64 flags 0x00 dlen 15               #222 [hci0] 19.029554
      ATT: Read Response (0x0b) len 10
        Value: 31302e302e302e313732
> HCI Event: Number of Completed Packets (0x13) plen 5    #223 [hci0] 19.303772
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #224 [hci0] 19.329773
      ATT: Read Request (0x0a) len 2
        Handle: 0x00bf
< ACL Data TX: Handle 64 flags 0x00 dlen 18               #225 [hci0] 19.360903
      ATT: Read Response (0x0b) len 13
        Value: 3235352e3235352e3235352e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #226 [hci0] 19.553228
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #227 [hci0] 19.569694
      ATT: Read Request (0x0a) len 2
        Handle: 0x00d1
< ACL Data TX: Handle 64 flags 0x00 dlen 13               #228 [hci0] 19.601731
      ATT: Read Response (0x0b) len 8
        Value: 31302e302e302e31
> HCI Event: Number of Completed Packets (0x13) plen 5    #229 [hci0] 19.803450
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #230 [hci0] 19.809737
      ATT: Read Request (0x0a) len 2
        Handle: 0x00d5
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #231 [hci0] 19.838368
      ATT: Read Response (0x0b) len 7
        Value: 302e302e302e30
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #232 [hci0] 20.022517
      ATT: Read Request (0x0a) len 2
        Handle: 0x00e3
> HCI Event: Number of Completed Packets (0x13) plen 5    #233 [hci0] 20.054753
        Num handles: 1
        Handle: 64
        Count: 1
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #234 [hci0] 20.069675
      ATT: Read Response (0x0b) len 4
        Value: 74727565
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #235 [hci0] 20.259947
      ATT: Read Request (0x0a) len 2
        Handle: 0x00d9
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #236 [hci0] 20.300035
      ATT: Read Response (0x0b) len 5
        Value: 66616c7365
> HCI Event: Number of Completed Packets (0x13) plen 5    #237 [hci0] 20.303077
        Num handles: 1
        Handle: 64
        Count: 1
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #238 [hci0] 20.407493
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #239 [hci0] 20.409871
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #240 [hci0] 20.410110
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #241 [hci0] 20.412256
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #242 [hci0] 20.412479
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #243 [hci0] 20.419311
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #244 [hci0] 20.419542
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #245 [hci0] 20.422861
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #246 [hci0] 20.499675
      ATT: Read Request (0x0a) len 2
        Handle: 0x00b8
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #247 [hci0] 20.528128
      ATT: Read Response (0x0b) len 7
        Value: 34303038383539
> HCI Event: Number of Completed Packets (0x13) plen 5    #248 [hci0] 20.553068
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #249 [hci0] 20.747175
      ATT: Read Request (0x0a) len 2
        Handle: 0x00dc
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #250 [hci0] 20.785261
      ATT: Read Response (0x0b) len 5
        Value: 3437383038
> HCI Event: Number of Completed Packets (0x13) plen 5    #251 [hci0] 20.803100
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #252 [hci0] 20.979802
      ATT: Read Request (0x0a) len 2
        Handle: 0x00df
< ACL Data TX: Handle 64 flags 0x00 dlen 11               #253 [hci0] 21.009048
      ATT: Read Response (0x0b) len 6
        Value: 6e6f726d616c
> HCI Event: Number of Completed Packets (0x13) plen 5    #254 [hci0] 21.053276
        Num handles: 1
        Handle: 64
        Count: 1
> HCI Event: Number of Completed Packets (0x13) plen 5    #255 [hci0] 21.304562
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #256 [hci0] 21.374842
      ATT: Read Request (0x0a) len 2
        Handle: 0x014a
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #257 [hci0] 21.375975
      ATT: Error Response (0x01) len 4
        Read Request (0x0a)
        Handle: 0x014a
        Error: Read Not Permitted (0x02)
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #258 [hci0] 21.579737
      ATT: Read Request (0x0a) len 2
        Handle: 0x00e6
< ACL Data TX: Handle 64 flags 0x00 dlen 22               #259 [hci0] 21.610337
      ATT: Read Response (0x0b) len 17
        Value: 68747470733a2f2f6f336875622e636f6d
> HCI Event: Number of Completed Packets (0x13) plen 5    #260 [hci0] 21.670591
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #261 [hci0] 21.819676
      ATT: Read Request (0x0a) len 2
        Handle: 0x00e6
< ACL Data TX: Handle 64 flags 0x00 dlen 22               #262 [hci0] 21.859144
      ATT: Read Response (0x0b) len 17
        Value: 68747470733a2f2f6f336875622e636f6d
> HCI Event: Number of Completed Packets (0x13) plen 5    #263 [hci0] 22.053180
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #264 [hci0] 22.209641
      ATT: Read Request (0x0a) len 2
        Handle: 0x00ff
< ACL Data TX: Handle 64 flags 0x00 dlen 8                #265 [hci0] 22.232801
      ATT: Read Response (0x0b) len 3
        Value: 302e30
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #266 [hci0] 22.389676
      ATT: Read Request (0x0a) len 2
        Handle: 0x0057
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #267 [hci0] 22.414704
      ATT: Read Response (0x0b) len 5
        Value: 3338302e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #268 [hci0] 22.429031
        Num handles: 1
        Handle: 64
        Count: 1
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #269 [hci0] 22.487826
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #270 [hci0] 22.489385
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #271 [hci0] 22.489484
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #272 [hci0] 22.492210
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #273 [hci0] 22.492328
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #274 [hci0] 22.494391
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #275 [hci0] 22.494491
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #276 [hci0] 22.495906
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #277 [hci0] 22.599649
      ATT: Read Request (0x0a) len 2
        Handle: 0x0106
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #278 [hci0] 22.623811
      ATT: Read Response (0x0b) len 2
        Value: 3830
> HCI Event: Number of Completed Packets (0x13) plen 5    #279 [hci0] 22.659739
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #280 [hci0] 22.809674
      ATT: Read Request (0x0a) len 2
        Handle: 0x0109
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #281 [hci0] 22.835913
      ATT: Read Response (0x0b) len 2
        Value: 3830
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #282 [hci0] 23.019608
      ATT: Read Request (0x0a) len 2
        Handle: 0x012b
> HCI Event: Number of Completed Packets (0x13) plen 5    #283 [hci0] 23.053263
        Num handles: 1
        Handle: 64
        Count: 1
< ACL Data TX: Handle 64 flags 0x00 dlen 17               #284 [hci0] 23.063725
      ATT: Read Response (0x0b) len 12
        Value: 303031364134354234463032
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #285 [hci0] 23.259631
      ATT: Read Request (0x0a) len 2
        Handle: 0x00c9
< ACL Data TX: Handle 64 flags 0x00 dlen 16               #286 [hci0] 23.287984
      ATT: Read Response (0x0b) len 11
        Value: 3132313431342f30303037
> HCI Event: Number of Completed Packets (0x13) plen 5    #287 [hci0] 23.303214
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #288 [hci0] 23.499636
      ATT: Read Request (0x0a) len 2
        Handle: 0x0134
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #289 [hci0] 23.522981
      ATT: Read Response (0x0b) len 4
        Value: 342e3139
> HCI Event: Number of Completed Packets (0x13) plen 5    #290 [hci0] 23.553257
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #291 [hci0] 23.709645
      ATT: Read Request (0x0a) len 2
        Handle: 0x0131
< ACL Data TX: Handle 64 flags 0x00 dlen 20               #292 [hci0] 23.753698
      ATT: Read Response (0x0b) len 15
        Value: 322e302e302d616c7068612e313137
> HCI Event: Number of Completed Packets (0x13) plen 5    #293 [hci0] 23.799928
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #294 [hci0] 23.919613
      ATT: Read Request (0x0a) len 2
        Handle: 0x00ec
< ACL Data TX: Handle 64 flags 0x00 dlen 22               #295 [hci0] 24.099444
      ATT: Read Response (0x0b) len 17
        Value: 30303a34303a41453a31313a32363a3830
> HCI Event: Number of Completed Packets (0x13) plen 5    #296 [hci0] 24.303300
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #297 [hci0] 24.339622
      ATT: Read Request (0x0a) len 2
        Handle: 0x00ef
< ACL Data TX: Handle 64 flags 0x00 dlen 22               #298 [hci0] 24.363082
      ATT: Read Response (0x0b) len 17
        Value: 30303a34303a41453a31313a32363a3831
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #299 [hci0] 24.549614
      ATT: Read Request (0x0a) len 2
        Handle: 0x012e
> HCI Event: Number of Completed Packets (0x13) plen 5    #300 [hci0] 24.562268
        Num handles: 1
        Handle: 64
        Count: 1
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #301 [hci0] 24.567253
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #302 [hci0] 24.568940
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #303 [hci0] 24.569047
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #304 [hci0] 24.570534
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #305 [hci0] 24.570636
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #306 [hci0] 24.573729
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #307 [hci0] 24.573833
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #308 [hci0] 24.575760
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #309 [hci0] 24.583194
      ATT: Read Response (0x0b) len 7
        Value: 323031382e3033
> HCI Event: Number of Completed Packets (0x13) plen 5    #310 [hci0] 24.803540
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #311 [hci0] 24.939664
      ATT: Read Request (0x0a) len 2
        Handle: 0x00f2
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #312 [hci0] 24.969000
      ATT: Read Response (0x0b) len 1
        Value: 30
> HCI Event: Number of Completed Packets (0x13) plen 5    #313 [hci0] 25.178650
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #314 [hci0] 25.179585
      ATT: Read Request (0x0a) len 2
        Handle: 0x00f6
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #315 [hci0] 25.212294
      ATT: Read Response (0x0b) len 1
        Value: 31
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #316 [hci0] 25.420035
      ATT: Read Request (0x0a) len 2
        Handle: 0x0016
> HCI Event: Number of Completed Packets (0x13) plen 5    #317 [hci0] 25.433343
        Num handles: 1
        Handle: 64
        Count: 1
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #318 [hci0] 25.450144
      ATT: Read Response (0x0b) len 5
        Value: 32302e3132
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #319 [hci0] 25.629869
      ATT: Read Request (0x0a) len 2
        Handle: 0x002e
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #320 [hci0] 25.659476
      ATT: Read Response (0x0b) len 5
        Value: 32302e3032
> HCI Event: Number of Completed Packets (0x13) plen 5    #321 [hci0] 25.679795
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #322 [hci0] 25.869551
      ATT: Read Request (0x0a) len 2
        Handle: 0x0032
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #323 [hci0] 25.901955
      ATT: Read Response (0x0b) len 5
        Value: 32302e3639
> HCI Event: Number of Completed Packets (0x13) plen 5    #324 [hci0] 25.928294
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #325 [hci0] 26.109632
      ATT: Read Request (0x0a) len 2
        Handle: 0x001e
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #326 [hci0] 26.143444
      ATT: Read Response (0x0b) len 1
        Value: 31
> HCI Event: Number of Completed Packets (0x13) plen 5    #327 [hci0] 26.178570
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #328 [hci0] 26.349544
      ATT: Read Request (0x0a) len 2
        Handle: 0x002a
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #329 [hci0] 26.385573
      ATT: Read Response (0x0b) len 1
        Value: 30
> HCI Event: Number of Completed Packets (0x13) plen 5    #330 [hci0] 26.428385
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #331 [hci0] 26.590031
      ATT: Read Request (0x0a) len 2
        Handle: 0x0115
< ACL Data TX: Handle 64 flags 0x00 dlen 8                #332 [hci0] 26.620533
      ATT: Read Response (0x0b) len 3
        Value: 333030
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #333 [hci0] 26.647265
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #334 [hci0] 26.648531
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #335 [hci0] 26.648616
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #336 [hci0] 26.649720
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #337 [hci0] 26.649796
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #338 [hci0] 26.657157
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #339 [hci0] 26.657259
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #340 [hci0] 26.658212
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5    #341 [hci0] 26.678308
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #342 [hci0] 26.829510
      ATT: Read Request (0x0a) len 2
        Handle: 0x001a
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #343 [hci0] 26.859130
      ATT: Read Response (0x0b) len 5
        Value: 33382e3132
> HCI Event: Number of Completed Packets (0x13) plen 5    #344 [hci0] 26.919658
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #345 [hci0] 27.039807
      ATT: Read Request (0x0a) len 2
        Handle: 0x0036
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #346 [hci0] 27.082581
      ATT: Read Response (0x0b) len 5
        Value: 33372e3738
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #347 [hci0] 27.279850
      ATT: Read Request (0x0a) len 2
        Handle: 0x0022
> HCI Event: Number of Completed Packets (0x13) plen 5    #348 [hci0] 27.303996
        Num handles: 1
        Handle: 64
        Count: 1
< ACL Data TX: Handle 64 flags 0x00 dlen 8                #349 [hci0] 27.310266
      ATT: Read Response (0x0b) len 3
        Value: 302e30
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #350 [hci0] 27.519495
      ATT: Read Request (0x0a) len 2
        Handle: 0x003a
< ACL Data TX: Handle 64 flags 0x00 dlen 11               #351 [hci0] 27.551491
      ATT: Read Response (0x0b) len 6
        Value: 363936302e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #352 [hci0] 27.554811
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #353 [hci0] 27.759488
      ATT: Read Request (0x0a) len 2
        Handle: 0x0026
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #354 [hci0] 27.798286
      ATT: Read Response (0x0b) len 2
        Value: 3339
> HCI Event: Number of Completed Packets (0x13) plen 5    #355 [hci0] 27.803954
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #356 [hci0] 27.999533
      ATT: Read Request (0x0a) len 2
        Handle: 0x0090
< ACL Data TX: Handle 64 flags 0x00 dlen 13               #357 [hci0] 28.030651
      ATT: Read Response (0x0b) len 8
        Value: 302e303030303030
> HCI Event: Number of Completed Packets (0x13) plen 5    #358 [hci0] 28.053486
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #359 [hci0] 28.239522
      ATT: Read Request (0x0a) len 2
        Handle: 0x0096
< ACL Data TX: Handle 64 flags 0x00 dlen 13               #360 [hci0] 28.274598
      ATT: Read Response (0x0b) len 8
        Value: 302e303030303030
> HCI Event: Number of Completed Packets (0x13) plen 5    #361 [hci0] 28.303577
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #362 [hci0] 28.479524
      ATT: Read Request (0x0a) len 2
        Handle: 0x0080
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #363 [hci0] 28.509526
      ATT: Read Response (0x0b) len 1
        Value: ff
> HCI Event: Number of Completed Packets (0x13) plen 5    #364 [hci0] 28.554117
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #365 [hci0] 28.720450
      ATT: Read Request (0x0a) len 2
        Handle: 0x008c
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #366 [hci0] 28.727310
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #367 [hci0] 28.731115
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #368 [hci0] 28.731231
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #369 [hci0] 28.733252
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #370 [hci0] 28.733360
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #371 [hci0] 28.740187
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #372 [hci0] 28.740297
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #373 [hci0] 28.741749
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #374 [hci0] 28.746472
      ATT: Read Response (0x0b) len 1
        Value: ff
> HCI Event: Number of Completed Packets (0x13) plen 5    #375 [hci0] 28.804858
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #376 [hci0] 28.899514
      ATT: Read Request (0x0a) len 2
        Handle: 0x0140
< ACL Data TX: Handle 64 flags 0x00 dlen 24               #377 [hci0] 28.900194
      ATT: Read Response (0x0b) len 19
        Value: 884101f09f9394856720a26047025b9ef90752
> HCI Event: Number of Completed Packets (0x13) plen 5    #378 [hci0] 28.959599
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #379 [hci0] 29.259504
      ATT: Read Request (0x0a) len 2
        Handle: 0x0102
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #380 [hci0] 29.283236
      ATT: Read Response (0x0b) len 5
        Value: 32302e3132
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #381 [hci0] 29.469466
      ATT: Read Request (0x0a) len 2
        Handle: 0x0012
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #382 [hci0] 29.490374
      ATT: Read Response (0x0b) len 1
        Value: 30
> HCI Event: Number of Completed Packets (0x13) plen 5    #383 [hci0] 29.529557
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #384 [hci0] 29.679497
      ATT: Read Request (0x0a) len 2
        Handle: 0x00cd
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #385 [hci0] 29.716740
      ATT: Read Response (0x0b) len 4
        Value: 44484350
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #386 [hci0] 29.800213
      ATT: Read Request (0x0a) len 2
        Handle: 0x00bb
< ACL Data TX: Handle 64 flags 0x00 dlen 15               #387 [hci0] 29.859780
      ATT: Read Response (0x0b) len 10
        Value: 31302e302e302e313732
> HCI Event: Number of Completed Packets (0x13) plen 5    #388 [hci0] 29.928665
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #389 [hci0] 29.950396
      ATT: Read Request (0x0a) len 2
        Handle: 0x00bf
< ACL Data TX: Handle 64 flags 0x00 dlen 18               #390 [hci0] 29.972077
      ATT: Read Response (0x0b) len 13
        Value: 3235352e3235352e3235352e30
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #391 [hci0] 30.010270
      ATT: Read Request (0x0a) len 2
        Handle: 0x00d1
> HCI Event: Number of Completed Packets (0x13) plen 5    #392 [hci0] 30.019328
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 13               #393 [hci0] 30.033395
      ATT: Read Response (0x0b) len 8
        Value: 31302e302e302e31
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #394 [hci0] 30.070249
      ATT: Read Request (0x0a) len 2
        Handle: 0x00d5
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #395 [hci0] 30.094837
      ATT: Read Response (0x0b) len 7
        Value: 302e302e302e30
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #396 [hci0] 30.130220
      ATT: Read Request (0x0a) len 2
        Handle: 0x00e3
> HCI Event: Number of Completed Packets (0x13) plen 5    #397 [hci0] 30.132144
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #398 [hci0] 30.162557
      ATT: Read Response (0x0b) len 4
        Value: 74727565
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #399 [hci0] 30.220240
      ATT: Read Request (0x0a) len 2
        Handle: 0x00d9
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #400 [hci0] 30.242132
      ATT: Read Response (0x0b) len 5
        Value: 66616c7365
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #401 [hci0] 30.280213
      ATT: Read Request (0x0a) len 2
        Handle: 0x00b8
> HCI Event: Number of Completed Packets (0x13) plen 5    #402 [hci0] 30.283529
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #403 [hci0] 30.315140
      ATT: Read Response (0x0b) len 7
        Value: 34303038383539
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #404 [hci0] 30.370203
      ATT: Read Request (0x0a) len 2
        Handle: 0x00dc
< ACL Data TX: Handle 64 flags 0x00 dlen 10               #405 [hci0] 30.426891
      ATT: Read Response (0x0b) len 5
        Value: 3437383038
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #406 [hci0] 30.490194
      ATT: Read Request (0x0a) len 2
        Handle: 0x00df
> HCI Event: Number of Completed Packets (0x13) plen 5    #407 [hci0] 30.492565
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 11               #408 [hci0] 30.532733
      ATT: Read Response (0x0b) len 6
        Value: 6e6f726d616c
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #409 [hci0] 30.580179
      ATT: Read Request (0x0a) len 2
        Handle: 0x00af
< ACL Data TX: Handle 64 flags 0x00 dlen 6                #410 [hci0] 30.602092
      ATT: Read Response (0x0b) len 1
        Value: 43
> ACL Data RX: Handle 64 flags 0x02 dlen 7                #411 [hci0] 30.670203
      ATT: Read Request (0x0a) len 2
        Handle: 0x00b2
> HCI Event: Number of Completed Packets (0x13) plen 5    #412 [hci0] 30.672483
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 7                #413 [hci0] 30.700230
      ATT: Read Response (0x0b) len 2
        Value: 6c78
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #414 [hci0] 30.807287
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #415 [hci0] 30.808785
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #416 [hci0] 30.808884
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #417 [hci0] 30.811885
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #418 [hci0] 30.812012
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #419 [hci0] 30.815993
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #420 [hci0] 30.816099
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #421 [hci0] 30.816760
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5    #422 [hci0] 30.928652
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #423 [hci0] 31.299915
      ATT: Write Request (0x12) len 4
        Handle: 0x00ce
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #424 [hci0] 31.300863
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #425 [hci0] 31.360165
      ATT: Write Request (0x12) len 4
        Handle: 0x00bc
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #426 [hci0] 31.361113
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #427 [hci0] 31.420192
      ATT: Write Request (0x12) len 4
        Handle: 0x00c0
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #428 [hci0] 31.421200
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #429 [hci0] 31.424830
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #430 [hci0] 31.480148
      ATT: Write Request (0x12) len 4
        Handle: 0x00d2
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #431 [hci0] 31.481150
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #432 [hci0] 31.540553
      ATT: Write Request (0x12) len 4
        Handle: 0x00d6
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #433 [hci0] 31.541519
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #434 [hci0] 31.543794
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #435 [hci0] 31.600351
      ATT: Write Request (0x12) len 4
        Handle: 0x00e0
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #436 [hci0] 31.601866
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #437 [hci0] 31.660339
      ATT: Write Request (0x12) len 4
        Handle: 0x0017
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #438 [hci0] 31.661402
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #439 [hci0] 31.665367
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #440 [hci0] 31.720194
      ATT: Write Request (0x12) len 4
        Handle: 0x002f
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #441 [hci0] 31.721135
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #442 [hci0] 31.780550
      ATT: Write Request (0x12) len 4
        Handle: 0x0033
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #443 [hci0] 31.781551
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #444 [hci0] 31.783791
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #445 [hci0] 31.840182
      ATT: Write Request (0x12) len 4
        Handle: 0x001f
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #446 [hci0] 31.841122
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #447 [hci0] 31.900146
      ATT: Write Request (0x12) len 4
        Handle: 0x002b
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #448 [hci0] 31.901170
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #449 [hci0] 31.903365
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #450 [hci0] 31.960469
      ATT: Write Request (0x12) len 4
        Handle: 0x001b
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #451 [hci0] 31.961472
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #452 [hci0] 32.020170
      ATT: Write Request (0x12) len 4
        Handle: 0x0037
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #453 [hci0] 32.021174
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #454 [hci0] 32.026170
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #455 [hci0] 32.080199
      ATT: Write Request (0x12) len 4
        Handle: 0x0023
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #456 [hci0] 32.081194
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #457 [hci0] 32.140336
      ATT: Write Request (0x12) len 4
        Handle: 0x003b
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #458 [hci0] 32.141372
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #459 [hci0] 32.143945
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #460 [hci0] 32.199840
      ATT: Write Request (0x12) len 4
        Handle: 0x0027
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #461 [hci0] 32.200847
      ATT: Write Response (0x13) len 0
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #462 [hci0] 32.260148
      ATT: Write Request (0x12) len 4
        Handle: 0x0081
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #463 [hci0] 32.261153
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #464 [hci0] 32.265317
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 11               #465 [hci0] 32.307308
      ATT: Handle Value Notification (0x1b) len 6
        Handle: 0x00cd
          Data: 44484350
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #466 [hci0] 32.319524
      ATT: Write Request (0x12) len 4
        Handle: 0x008d
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #467 [hci0] 32.320495
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #468 [hci0] 32.349324
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 17               #469 [hci0] 32.365572
      ATT: Handle Value Notification (0x1b) len 12
        Handle: 0x00bb
          Data: 31302e302e302e313732
> ACL Data RX: Handle 64 flags 0x02 dlen 9                #470 [hci0] 32.379708
      ATT: Write Request (0x12) len 4
        Handle: 0x0103
          Data: 0100
< ACL Data TX: Handle 64 flags 0x00 dlen 5                #471 [hci0] 32.380757
      ATT: Write Response (0x13) len 0
> HCI Event: Number of Completed Packets (0x13) plen 5    #472 [hci0] 32.409356
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 20               #473 [hci0] 32.425882
      ATT: Handle Value Notification (0x1b) len 15
        Handle: 0x00bf
          Data: 3235352e3235352e3235352e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #474 [hci0] 32.469453
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 15               #475 [hci0] 32.485960
      ATT: Handle Value Notification (0x1b) len 10
        Handle: 0x00d1
          Data: 31302e302e302e31
< ACL Data TX: Handle 64 flags 0x00 dlen 14               #476 [hci0] 32.554156
      ATT: Handle Value Notification (0x1b) len 9
        Handle: 0x00d5
          Data: 302e302e302e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #477 [hci0] 32.589431
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 13               #478 [hci0] 32.607254
      ATT: Handle Value Notification (0x1b) len 8
        Handle: 0x00df
          Data: 6e6f726d616c
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #479 [hci0] 32.673240
      ATT: Handle Value Notification (0x1b) len 7
        Handle: 0x0016
          Data: 32302e3132
> HCI Event: Number of Completed Packets (0x13) plen 5    #480 [hci0] 32.709552
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #481 [hci0] 32.728570
      ATT: Handle Value Notification (0x1b) len 7
        Handle: 0x002e
          Data: 32302e3032
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #482 [hci0] 32.786965
      ATT: Handle Value Notification (0x1b) len 7
        Handle: 0x0032
          Data: 32302e3639
> HCI Event: Number of Completed Packets (0x13) plen 5    #483 [hci0] 32.829436
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 8                #484 [hci0] 32.845959
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x001e
          Data: 31
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #485 [hci0] 32.887325
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #486 [hci0] 32.889050
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #487 [hci0] 32.889187
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #488 [hci0] 32.892489
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #489 [hci0] 32.892593
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #490 [hci0] 32.898820
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #491 [hci0] 32.898922
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #492 [hci0] 32.900051
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< ACL Data TX: Handle 64 flags 0x00 dlen 8                #493 [hci0] 32.906065
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x002a
          Data: 30
> HCI Event: Number of Completed Packets (0x13) plen 5    #494 [hci0] 32.949448
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #495 [hci0] 32.967513
      ATT: Handle Value Notification (0x1b) len 7
        Handle: 0x001a
          Data: 33382e3132
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #496 [hci0] 33.026695
      ATT: Handle Value Notification (0x1b) len 7
        Handle: 0x0036
          Data: 33372e3738
< ACL Data TX: Handle 64 flags 0x00 dlen 11               #497 [hci0] 33.086563
      ATT: Handle Value Notification (0x1b) len 6
        Handle: 0x0022
          Data: 31322e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #498 [hci0] 33.099314
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 13               #499 [hci0] 33.146622
      ATT: Handle Value Notification (0x1b) len 8
        Handle: 0x003a
          Data: 363936302e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #500 [hci0] 33.190184
        Num handles: 1
        Handle: 64
        Count: 2
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #501 [hci0] 33.205824
      ATT: Handle Value Notification (0x1b) len 4
        Handle: 0x0026
          Data: 3339
< ACL Data TX: Handle 64 flags 0x00 dlen 12               #502 [hci0] 33.386084
      ATT: Handle Value Notification (0x1b) len 7
        Handle: 0x0102
          Data: 32302e3132
> HCI Event: Number of Completed Packets (0x13) plen 5    #503 [hci0] 33.429093
        Num handles: 1
        Handle: 64
        Count: 1
> HCI Event: Number of Completed Packets (0x13) plen 5    #504 [hci0] 33.679471
        Num handles: 1
        Handle: 64
        Count: 1
< ACL Data TX: Handle 64 flags 0x00 dlen 13               #505 [hci0] 34.147751
      ATT: Handle Value Notification (0x1b) len 8
        Handle: 0x003a
          Data: 353435382e30
> HCI Event: Number of Completed Packets (0x13) plen 5    #506 [hci0] 34.430344
        Num handles: 1
        Handle: 64
        Count: 1
> ACL Data RX: Handle 64 flags 0x02 dlen 8                #507 [hci0] 34.629385
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x0016
          Data: 56
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #508 [hci0] 34.967304
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #509 [hci0] 34.969326
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #510 [hci0] 34.969431
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #511 [hci0] 34.971340
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #512 [hci0] 34.971449
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #513 [hci0] 34.974061
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #514 [hci0] 34.974164
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #515 [hci0] 34.975646
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #516 [hci0] 37.047297
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #517 [hci0] 37.049453
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #518 [hci0] 37.049560
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #519 [hci0] 37.051932
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #520 [hci0] 37.052041
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #521 [hci0] 37.057000
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #522 [hci0] 37.057220
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #523 [hci0] 37.058216
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #524 [hci0] 39.127281
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #525 [hci0] 39.128857
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #526 [hci0] 39.128951
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #527 [hci0] 39.130785
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #528 [hci0] 39.130881
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #529 [hci0] 39.133950
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #530 [hci0] 39.134048
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #531 [hci0] 39.135240
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #532 [hci0] 41.207548
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #533 [hci0] 41.209057
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #534 [hci0] 41.209158
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #535 [hci0] 41.212789
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #536 [hci0] 41.212903
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #537 [hci0] 41.213871
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #538 [hci0] 41.213963
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #539 [hci0] 41.214978
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #540 [hci0] 43.287292
        Length: 29
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Google (0xfeaa)
        Service Data (UUID 0xfeaa): 00005c8e6b8bf66a4ab7a3590016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #541 [hci0] 43.288771
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #542 [hci0] 43.288870
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #543 [hci0] 43.290069
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #544 [hci0] 43.290170
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #545 [hci0] 43.293277
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #546 [hci0] 43.293385
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4               #547 [hci0] 43.294794
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                #548 [hci0] 44.214349
      ATT: Handle Value Notification (0x1b) len 4
        Handle: 0x0026
          Data: 3434
> HCI Event: Number of Completed Packets (0x13) plen 5    #549 [hci0] 44.430583
        Num handles: 1
        Handle: 64
        Count: 1
< HCI Command: LE Set Advertisin.. (0x08|0x0008) plen 32  #550 [hci0] 45.367178
        Length: 17
        Flags: 0x02
          LE General Discoverable Mode
        16-bit Service UUIDs (complete): 1 entry
          Unknown (0x4822)
        Company: not assigned (1694)
          Data: 0016a45b4f02
> HCI Event: Command Complete (0x0e) plen 4               #551 [hci0] 45.368614
      LE Set Advertising Data (0x08|0x0008) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise E.. (0x08|0x000a) plen 1  #552 [hci0] 45.368700
        Advertising: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4               #553 [hci0] 45.370622
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertisin.. (0x08|0x0006) plen 15  #554 [hci0] 45.370705
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
      

^ permalink raw reply	[flat|nested] 13+ messages in thread

* RE: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-13  5:59 Disabled bluetooth cache. But the app still getting wrong data? Kenny Bian
@ 2021-04-13  6:39 ` Jamie Mccrae
  2021-04-13 17:17   ` Kenny Bian
  2021-04-13 21:57   ` Luiz Augusto von Dentz
  0 siblings, 2 replies; 13+ messages in thread
From: Jamie Mccrae @ 2021-04-13  6:39 UTC (permalink / raw)
  To: Kenny Bian, linux-bluetooth

Hi Kenny,
Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
Thanks,
Jamie

-----Original Message-----
From: Kenny Bian <kennybian@gmail.com>
Sent: 13 April 2021 06:59
To: linux-bluetooth@vger.kernel.org
Subject: Disabled bluetooth cache. But the app still getting wrong data?

EXTERNAL EMAIL: Be careful with attachments and links.

Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
In order to keep the pairing information, the "/var/lib/bluetooth"
folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
"/etc/bluetooth/main.conf":
[GATT]
Cache = no

But recently, we saw the problem again even if the bluetooth cache is
disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.

The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.

I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.

Questions:
1. How is it possible that this still happens even if the bluetooth cache is disabled?
2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
3. Is there anything else we should look into?

We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.

Thanks!
THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-13  6:39 ` Jamie Mccrae
@ 2021-04-13 17:17   ` Kenny Bian
  2021-04-13 21:57   ` Luiz Augusto von Dentz
  1 sibling, 0 replies; 13+ messages in thread
From: Kenny Bian @ 2021-04-13 17:17 UTC (permalink / raw)
  To: Jamie Mccrae; +Cc: linux-bluetooth

Hi Jamie,

Thank you for your email. Do you know how to add "Service Changed
Indication"? We would like to support that. But we don't know how to
do it.

In fact, I posted the question before:
https://www.spinics.net/lists/linux-bluetooth/msg89959.html. It seems
"If you are registering the services with Bluetoothd then it should
generate the service change". Our GATT server is based on
https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test/example-gatt-server.
By saying "registering the services", does it mean our code should
call "RegisterApplication()"? We did call RegisterApplication(). But
we never saw the "[ServiceChanged]"
section(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/doc/settings-storage.txt#n321).
Please let us know if you know how to add "Service Changed
Indication".

Thanks!
Kenny

Kenny

On Mon, Apr 12, 2021 at 11:39 PM Jamie Mccrae
<Jamie.Mccrae@lairdconnect.com> wrote:
>
> Hi Kenny,
> Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> Thanks,
> Jamie
>
> -----Original Message-----
> From: Kenny Bian <kennybian@gmail.com>
> Sent: 13 April 2021 06:59
> To: linux-bluetooth@vger.kernel.org
> Subject: Disabled bluetooth cache. But the app still getting wrong data?
>
> EXTERNAL EMAIL: Be careful with attachments and links.
>
> Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> In order to keep the pairing information, the "/var/lib/bluetooth"
> folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> "/etc/bluetooth/main.conf":
> [GATT]
> Cache = no
>
> But recently, we saw the problem again even if the bluetooth cache is
> disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
>
> The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
>
> I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
>
> Questions:
> 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> 3. Is there anything else we should look into?
>
> We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
>
> Thanks!
> THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-13  6:39 ` Jamie Mccrae
  2021-04-13 17:17   ` Kenny Bian
@ 2021-04-13 21:57   ` Luiz Augusto von Dentz
  2021-04-14  4:46     ` Kenny Bian
  1 sibling, 1 reply; 13+ messages in thread
From: Luiz Augusto von Dentz @ 2021-04-13 21:57 UTC (permalink / raw)
  To: Jamie Mccrae; +Cc: Kenny Bian, linux-bluetooth

Hi Jamie, Brian,

On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
<Jamie.Mccrae@lairdconnect.com> wrote:
>
> Hi Kenny,
> Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.

Yep, and while at it implement the so called Robust Caching feature so
we can detect if anything has changed by reading the DB Hash.

> Thanks,
> Jamie
>
> -----Original Message-----
> From: Kenny Bian <kennybian@gmail.com>
> Sent: 13 April 2021 06:59
> To: linux-bluetooth@vger.kernel.org
> Subject: Disabled bluetooth cache. But the app still getting wrong data?
>
> EXTERNAL EMAIL: Be careful with attachments and links.
>
> Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> In order to keep the pairing information, the "/var/lib/bluetooth"
> folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> "/etc/bluetooth/main.conf":
> [GATT]
> Cache = no

When you say the app can't handle changed service do you mean BlueZ
doesn't emit changes to the attributes (via Service Changed) or is it
really the application not being able to handle the changes?

> But recently, we saw the problem again even if the bluetooth cache is
> disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.

So BlueZ is acting as the server, right? The Cache only applies to the
client portion, there is no such thing as disabling the remote cache.
I don't see any incoming Read By Group Request from the remote so it
is very likely that it has cached the values, there is no Read By Type
for the DB Hash either which is quite surprising to me since that is
required for stacks supporting Robust Caching which I believe is the
case of iOS.

Anyway, I would check that the following lines are being triggered:

When starting:

https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798

On connect:

https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741

If those lines are not being triggered it is likely a client problem
which for some reason had not subscribed to received service changes
for some reason, if it doesn't subscribe to service changes then it
shall not cache any attribute and attempt to rediscover on every
connection.

> The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
>
> I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
>
> Questions:
> 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> 3. Is there anything else we should look into?
>
> We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
>
> Thanks!
> THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.



-- 
Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-13 21:57   ` Luiz Augusto von Dentz
@ 2021-04-14  4:46     ` Kenny Bian
  2021-04-15  5:44       ` Kenny Bian
  0 siblings, 1 reply; 13+ messages in thread
From: Kenny Bian @ 2021-04-14  4:46 UTC (permalink / raw)
  To: Luiz Augusto von Dentz; +Cc: Jamie Mccrae, linux-bluetooth

Hi Jamie, Luiz,

Thanks for your info.

Luiz, to answer your questions:
BlueZ doesn't seem to emit "Service Changed Indication". Or it does
emit it, but we don't know how to verify it.
Yes, BlueZ acts as a GATT server which runs on Linux.

So my questions:
How can I tell if "Service Changed Indication" is working? I need to
show it to our app developers that the GATT server does send the
"Service Changed Indication" when there is a service change.
By disabling the GATT's cache in "/etc/bluetooth/main.conf", the
"Service Changed Indication" is disabled?
Can "Service Changed Indication" be enabled in a conf file? Or should
it be done in the Python code? Could you please help find out that
info?
Our GATT server is based on the Python code
examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
I don't know how to enable "Service Changed Indication" or "Robust
Caching" in Python code on the GATT server side. There is no document
or code samples about that. Please let me know if there is any
document or Python code example.

Thanks!
Kenny

On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
<luiz.dentz@gmail.com> wrote:
>
> Hi Jamie, Brian,
>
> On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> <Jamie.Mccrae@lairdconnect.com> wrote:
> >
> > Hi Kenny,
> > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
>
> Yep, and while at it implement the so called Robust Caching feature so
> we can detect if anything has changed by reading the DB Hash.
>
> > Thanks,
> > Jamie
> >
> > -----Original Message-----
> > From: Kenny Bian <kennybian@gmail.com>
> > Sent: 13 April 2021 06:59
> > To: linux-bluetooth@vger.kernel.org
> > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> >
> > EXTERNAL EMAIL: Be careful with attachments and links.
> >
> > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > In order to keep the pairing information, the "/var/lib/bluetooth"
> > folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> > "/etc/bluetooth/main.conf":
> > [GATT]
> > Cache = no
>
> When you say the app can't handle changed service do you mean BlueZ
> doesn't emit changes to the attributes (via Service Changed) or is it
> really the application not being able to handle the changes?
>
> > But recently, we saw the problem again even if the bluetooth cache is
> > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
>
> So BlueZ is acting as the server, right? The Cache only applies to the
> client portion, there is no such thing as disabling the remote cache.
> I don't see any incoming Read By Group Request from the remote so it
> is very likely that it has cached the values, there is no Read By Type
> for the DB Hash either which is quite surprising to me since that is
> required for stacks supporting Robust Caching which I believe is the
> case of iOS.
>
> Anyway, I would check that the following lines are being triggered:
>
> When starting:
>
> https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798
>
> On connect:
>
> https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741
>
> If those lines are not being triggered it is likely a client problem
> which for some reason had not subscribed to received service changes
> for some reason, if it doesn't subscribe to service changes then it
> shall not cache any attribute and attempt to rediscover on every
> connection.
>
> > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> >
> > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> >
> > Questions:
> > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > 3. Is there anything else we should look into?
> >
> > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> >
> > Thanks!
> > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
>
>
>
> --
> Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-14  4:46     ` Kenny Bian
@ 2021-04-15  5:44       ` Kenny Bian
  2021-04-15 20:31         ` Luiz Augusto von Dentz
  0 siblings, 1 reply; 13+ messages in thread
From: Kenny Bian @ 2021-04-15  5:44 UTC (permalink / raw)
  To: Luiz Augusto von Dentz; +Cc: Jamie Mccrae, linux-bluetooth

Hi Luiz,

There is a UI example of nRF Connect which shows the "Service Changed
Indication" is under "Generic
Attribute"(http://forum.espruino.com/conversations/357737/). We're
using BlueZ 5.48. I tried to add it by modifying example-gatt-server:


class ServiceChangedChrc(Characteristic):
    SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'

    def __init__(self, bus, index, service):
        Characteristic.__init__(
                self, bus, index,
                self.SCI_UUID,
                ['indicate'],
                service)

    def IndicateValue(self, options):
        # This function doesn't exist. Just list it here.
        pass


class ServiceChangedService(Service):
    MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'

    def __init__(self, bus, index):
        Service.__init__(self, bus, index, self.MY_UUID, True)
        self.add_characteristic(ServiceChangedChrc(bus, 0, self))


class Application(dbus.service.Object):
    """
    org.bluez.GattApplication1 interface implementation
    """
    def __init__(self, bus):
        self.path = '/'
        self.services = []
        dbus.service.Object.__init__(self, bus, self.path)
        self.add_service(HeartRateService(bus, 0))
        self.add_service(BatteryService(bus, 1))
        self.add_service(TestService(bus, 2))
        self.add_service(ServiceChangedService(bus, 3))


When I run it, there is "Failed to register application:
org.bluez.Error.Failed: Failed to create entry in database". That is
in the function client_ready_cb() in gatt-database.c in BlueZ code. Do
you know how to fix it?

Thanks!
Kenny

On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
>
> Hi Jamie, Luiz,
>
> Thanks for your info.
>
> Luiz, to answer your questions:
> BlueZ doesn't seem to emit "Service Changed Indication". Or it does
> emit it, but we don't know how to verify it.
> Yes, BlueZ acts as a GATT server which runs on Linux.
>
> So my questions:
> How can I tell if "Service Changed Indication" is working? I need to
> show it to our app developers that the GATT server does send the
> "Service Changed Indication" when there is a service change.
> By disabling the GATT's cache in "/etc/bluetooth/main.conf", the
> "Service Changed Indication" is disabled?
> Can "Service Changed Indication" be enabled in a conf file? Or should
> it be done in the Python code? Could you please help find out that
> info?
> Our GATT server is based on the Python code
> examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> I don't know how to enable "Service Changed Indication" or "Robust
> Caching" in Python code on the GATT server side. There is no document
> or code samples about that. Please let me know if there is any
> document or Python code example.
>
> Thanks!
> Kenny
>
> On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
> <luiz.dentz@gmail.com> wrote:
> >
> > Hi Jamie, Brian,
> >
> > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> > <Jamie.Mccrae@lairdconnect.com> wrote:
> > >
> > > Hi Kenny,
> > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> >
> > Yep, and while at it implement the so called Robust Caching feature so
> > we can detect if anything has changed by reading the DB Hash.
> >
> > > Thanks,
> > > Jamie
> > >
> > > -----Original Message-----
> > > From: Kenny Bian <kennybian@gmail.com>
> > > Sent: 13 April 2021 06:59
> > > To: linux-bluetooth@vger.kernel.org
> > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > >
> > > EXTERNAL EMAIL: Be careful with attachments and links.
> > >
> > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> > > "/etc/bluetooth/main.conf":
> > > [GATT]
> > > Cache = no
> >
> > When you say the app can't handle changed service do you mean BlueZ
> > doesn't emit changes to the attributes (via Service Changed) or is it
> > really the application not being able to handle the changes?
> >
> > > But recently, we saw the problem again even if the bluetooth cache is
> > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> >
> > So BlueZ is acting as the server, right? The Cache only applies to the
> > client portion, there is no such thing as disabling the remote cache.
> > I don't see any incoming Read By Group Request from the remote so it
> > is very likely that it has cached the values, there is no Read By Type
> > for the DB Hash either which is quite surprising to me since that is
> > required for stacks supporting Robust Caching which I believe is the
> > case of iOS.
> >
> > Anyway, I would check that the following lines are being triggered:
> >
> > When starting:
> >
> > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798
> >
> > On connect:
> >
> > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741
> >
> > If those lines are not being triggered it is likely a client problem
> > which for some reason had not subscribed to received service changes
> > for some reason, if it doesn't subscribe to service changes then it
> > shall not cache any attribute and attempt to rediscover on every
> > connection.
> >
> > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > >
> > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > >
> > > Questions:
> > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > 3. Is there anything else we should look into?
> > >
> > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > >
> > > Thanks!
> > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> >
> >
> >
> > --
> > Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-15  5:44       ` Kenny Bian
@ 2021-04-15 20:31         ` Luiz Augusto von Dentz
  2021-04-16  0:20           ` Kenny Bian
  0 siblings, 1 reply; 13+ messages in thread
From: Luiz Augusto von Dentz @ 2021-04-15 20:31 UTC (permalink / raw)
  To: Kenny Bian; +Cc: Jamie Mccrae, linux-bluetooth

Hi Kenny,

On Wed, Apr 14, 2021 at 10:44 PM Kenny Bian <kennybian@gmail.com> wrote:
>
> Hi Luiz,
>
> There is a UI example of nRF Connect which shows the "Service Changed
> Indication" is under "Generic
> Attribute"(http://forum.espruino.com/conversations/357737/). We're
> using BlueZ 5.48. I tried to add it by modifying example-gatt-server:


You should have mentioned that you are using 5.48, you need the following patch:

commit a0b886e26c83ad4dfbf0b2b2e024c8ce9ead9a7d
Author: Szymon Janc <szymon.janc@codecoup.pl>
Date:   Wed Mar 28 12:10:55 2018 +0200

    gatt: Add support for storing Service Changed CCC value

    This adds support for storing CCC value of Service Changed
    characteristic. Once bluetoothd is restart stored values are read
    and any device subscribed to indications will receive Service Changed
    indication with 0x00010-0xffff value. This is to invalidate any
    non-core services since there is no way to verify if applications
    will register their services in same order (or at all).

    This fix accessing invalid handles by stacks that rely only on Service
    Changed indication for rediscovery ie. Apple iOS.

Or upgrade to a BlueZ release that has the above patch, which should be 5.50:

+ver 5.50:
+       Fix issue with GATT and reading long values.
+       Fix issue with GATT and reading multiple includes.
+       Fix issue with GATT and service changes when offline.
+       Fix issue with handling secondary service discovery.
+       Fix issue with handling persistency of CCC values.

>
> class ServiceChangedChrc(Characteristic):
>     SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'
>
>     def __init__(self, bus, index, service):
>         Characteristic.__init__(
>                 self, bus, index,
>                 self.SCI_UUID,
>                 ['indicate'],
>                 service)
>
>     def IndicateValue(self, options):
>         # This function doesn't exist. Just list it here.
>         pass
>
>
> class ServiceChangedService(Service):
>     MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'
>
>     def __init__(self, bus, index):
>         Service.__init__(self, bus, index, self.MY_UUID, True)
>         self.add_characteristic(ServiceChangedChrc(bus, 0, self))
>
>
> class Application(dbus.service.Object):
>     """
>     org.bluez.GattApplication1 interface implementation
>     """
>     def __init__(self, bus):
>         self.path = '/'
>         self.services = []
>         dbus.service.Object.__init__(self, bus, self.path)
>         self.add_service(HeartRateService(bus, 0))
>         self.add_service(BatteryService(bus, 1))
>         self.add_service(TestService(bus, 2))
>         self.add_service(ServiceChangedService(bus, 3))
>
>
> When I run it, there is "Failed to register application:
> org.bluez.Error.Failed: Failed to create entry in database". That is
> in the function client_ready_cb() in gatt-database.c in BlueZ code. Do
> you know how to fix it?

You don't need to register Service Changed, the daemon already takes
care of registering it and there could only be one Service Changed in
the database.

> Thanks!
> Kenny
>
> On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
> >
> > Hi Jamie, Luiz,
> >
> > Thanks for your info.
> >
> > Luiz, to answer your questions:
> > BlueZ doesn't seem to emit "Service Changed Indication". Or it does
> > emit it, but we don't know how to verify it.
> > Yes, BlueZ acts as a GATT server which runs on Linux.
> >
> > So my questions:
> > How can I tell if "Service Changed Indication" is working? I need to
> > show it to our app developers that the GATT server does send the
> > "Service Changed Indication" when there is a service change.
> > By disabling the GATT's cache in "/etc/bluetooth/main.conf", the
> > "Service Changed Indication" is disabled?
> > Can "Service Changed Indication" be enabled in a conf file? Or should
> > it be done in the Python code? Could you please help find out that
> > info?
> > Our GATT server is based on the Python code
> > examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> > I don't know how to enable "Service Changed Indication" or "Robust
> > Caching" in Python code on the GATT server side. There is no document
> > or code samples about that. Please let me know if there is any
> > document or Python code example.
> >
> > Thanks!
> > Kenny
> >
> > On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
> > <luiz.dentz@gmail.com> wrote:
> > >
> > > Hi Jamie, Brian,
> > >
> > > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> > > <Jamie.Mccrae@lairdconnect.com> wrote:
> > > >
> > > > Hi Kenny,
> > > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> > >
> > > Yep, and while at it implement the so called Robust Caching feature so
> > > we can detect if anything has changed by reading the DB Hash.
> > >
> > > > Thanks,
> > > > Jamie
> > > >
> > > > -----Original Message-----
> > > > From: Kenny Bian <kennybian@gmail.com>
> > > > Sent: 13 April 2021 06:59
> > > > To: linux-bluetooth@vger.kernel.org
> > > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > > >
> > > > EXTERNAL EMAIL: Be careful with attachments and links.
> > > >
> > > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > > folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> > > > "/etc/bluetooth/main.conf":
> > > > [GATT]
> > > > Cache = no
> > >
> > > When you say the app can't handle changed service do you mean BlueZ
> > > doesn't emit changes to the attributes (via Service Changed) or is it
> > > really the application not being able to handle the changes?
> > >
> > > > But recently, we saw the problem again even if the bluetooth cache is
> > > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> > >
> > > So BlueZ is acting as the server, right? The Cache only applies to the
> > > client portion, there is no such thing as disabling the remote cache.
> > > I don't see any incoming Read By Group Request from the remote so it
> > > is very likely that it has cached the values, there is no Read By Type
> > > for the DB Hash either which is quite surprising to me since that is
> > > required for stacks supporting Robust Caching which I believe is the
> > > case of iOS.
> > >
> > > Anyway, I would check that the following lines are being triggered:
> > >
> > > When starting:
> > >
> > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798
> > >
> > > On connect:
> > >
> > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741
> > >
> > > If those lines are not being triggered it is likely a client problem
> > > which for some reason had not subscribed to received service changes
> > > for some reason, if it doesn't subscribe to service changes then it
> > > shall not cache any attribute and attempt to rediscover on every
> > > connection.
> > >
> > > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > > >
> > > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > > >
> > > > Questions:
> > > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > > 3. Is there anything else we should look into?
> > > >
> > > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > > >
> > > > Thanks!
> > > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> > >
> > >
> > >
> > > --
> > > Luiz Augusto von Dentz



-- 
Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-15 20:31         ` Luiz Augusto von Dentz
@ 2021-04-16  0:20           ` Kenny Bian
  2021-04-16  0:49             ` Luiz Augusto von Dentz
  0 siblings, 1 reply; 13+ messages in thread
From: Kenny Bian @ 2021-04-16  0:20 UTC (permalink / raw)
  To: Luiz Augusto von Dentz; +Cc: Jamie Mccrae, linux-bluetooth

Hi Luiz,

Thank you so much. I appreciate it.

That was my bad. I just checked. Our system is Ubuntu 18.04. The BlueZ
version is "5.48-0ubuntu3.4" which is different from the versions in
http://www.bluez.org/. I'm trying to figure out if this version
includes the version 5.50. Do you know the corresponding BlueZ version
for "5.48-0ubuntu3.4"?

Thanks!
Kenny

On Thu, Apr 15, 2021 at 1:31 PM Luiz Augusto von Dentz
<luiz.dentz@gmail.com> wrote:
>
> Hi Kenny,
>
> On Wed, Apr 14, 2021 at 10:44 PM Kenny Bian <kennybian@gmail.com> wrote:
> >
> > Hi Luiz,
> >
> > There is a UI example of nRF Connect which shows the "Service Changed
> > Indication" is under "Generic
> > Attribute"(http://forum.espruino.com/conversations/357737/). We're
> > using BlueZ 5.48. I tried to add it by modifying example-gatt-server:
>
>
> You should have mentioned that you are using 5.48, you need the following patch:
>
> commit a0b886e26c83ad4dfbf0b2b2e024c8ce9ead9a7d
> Author: Szymon Janc <szymon.janc@codecoup.pl>
> Date:   Wed Mar 28 12:10:55 2018 +0200
>
>     gatt: Add support for storing Service Changed CCC value
>
>     This adds support for storing CCC value of Service Changed
>     characteristic. Once bluetoothd is restart stored values are read
>     and any device subscribed to indications will receive Service Changed
>     indication with 0x00010-0xffff value. This is to invalidate any
>     non-core services since there is no way to verify if applications
>     will register their services in same order (or at all).
>
>     This fix accessing invalid handles by stacks that rely only on Service
>     Changed indication for rediscovery ie. Apple iOS.
>
> Or upgrade to a BlueZ release that has the above patch, which should be 5.50:
>
> +ver 5.50:
> +       Fix issue with GATT and reading long values.
> +       Fix issue with GATT and reading multiple includes.
> +       Fix issue with GATT and service changes when offline.
> +       Fix issue with handling secondary service discovery.
> +       Fix issue with handling persistency of CCC values.
>
> >
> > class ServiceChangedChrc(Characteristic):
> >     SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'
> >
> >     def __init__(self, bus, index, service):
> >         Characteristic.__init__(
> >                 self, bus, index,
> >                 self.SCI_UUID,
> >                 ['indicate'],
> >                 service)
> >
> >     def IndicateValue(self, options):
> >         # This function doesn't exist. Just list it here.
> >         pass
> >
> >
> > class ServiceChangedService(Service):
> >     MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'
> >
> >     def __init__(self, bus, index):
> >         Service.__init__(self, bus, index, self.MY_UUID, True)
> >         self.add_characteristic(ServiceChangedChrc(bus, 0, self))
> >
> >
> > class Application(dbus.service.Object):
> >     """
> >     org.bluez.GattApplication1 interface implementation
> >     """
> >     def __init__(self, bus):
> >         self.path = '/'
> >         self.services = []
> >         dbus.service.Object.__init__(self, bus, self.path)
> >         self.add_service(HeartRateService(bus, 0))
> >         self.add_service(BatteryService(bus, 1))
> >         self.add_service(TestService(bus, 2))
> >         self.add_service(ServiceChangedService(bus, 3))
> >
> >
> > When I run it, there is "Failed to register application:
> > org.bluez.Error.Failed: Failed to create entry in database". That is
> > in the function client_ready_cb() in gatt-database.c in BlueZ code. Do
> > you know how to fix it?
>
> You don't need to register Service Changed, the daemon already takes
> care of registering it and there could only be one Service Changed in
> the database.
>
> > Thanks!
> > Kenny
> >
> > On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
> > >
> > > Hi Jamie, Luiz,
> > >
> > > Thanks for your info.
> > >
> > > Luiz, to answer your questions:
> > > BlueZ doesn't seem to emit "Service Changed Indication". Or it does
> > > emit it, but we don't know how to verify it.
> > > Yes, BlueZ acts as a GATT server which runs on Linux.
> > >
> > > So my questions:
> > > How can I tell if "Service Changed Indication" is working? I need to
> > > show it to our app developers that the GATT server does send the
> > > "Service Changed Indication" when there is a service change.
> > > By disabling the GATT's cache in "/etc/bluetooth/main.conf", the
> > > "Service Changed Indication" is disabled?
> > > Can "Service Changed Indication" be enabled in a conf file? Or should
> > > it be done in the Python code? Could you please help find out that
> > > info?
> > > Our GATT server is based on the Python code
> > > examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> > > I don't know how to enable "Service Changed Indication" or "Robust
> > > Caching" in Python code on the GATT server side. There is no document
> > > or code samples about that. Please let me know if there is any
> > > document or Python code example.
> > >
> > > Thanks!
> > > Kenny
> > >
> > > On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
> > > <luiz.dentz@gmail.com> wrote:
> > > >
> > > > Hi Jamie, Brian,
> > > >
> > > > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> > > > <Jamie.Mccrae@lairdconnect.com> wrote:
> > > > >
> > > > > Hi Kenny,
> > > > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> > > >
> > > > Yep, and while at it implement the so called Robust Caching feature so
> > > > we can detect if anything has changed by reading the DB Hash.
> > > >
> > > > > Thanks,
> > > > > Jamie
> > > > >
> > > > > -----Original Message-----
> > > > > From: Kenny Bian <kennybian@gmail.com>
> > > > > Sent: 13 April 2021 06:59
> > > > > To: linux-bluetooth@vger.kernel.org
> > > > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > > > >
> > > > > EXTERNAL EMAIL: Be careful with attachments and links.
> > > > >
> > > > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > > > folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> > > > > "/etc/bluetooth/main.conf":
> > > > > [GATT]
> > > > > Cache = no
> > > >
> > > > When you say the app can't handle changed service do you mean BlueZ
> > > > doesn't emit changes to the attributes (via Service Changed) or is it
> > > > really the application not being able to handle the changes?
> > > >
> > > > > But recently, we saw the problem again even if the bluetooth cache is
> > > > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> > > >
> > > > So BlueZ is acting as the server, right? The Cache only applies to the
> > > > client portion, there is no such thing as disabling the remote cache.
> > > > I don't see any incoming Read By Group Request from the remote so it
> > > > is very likely that it has cached the values, there is no Read By Type
> > > > for the DB Hash either which is quite surprising to me since that is
> > > > required for stacks supporting Robust Caching which I believe is the
> > > > case of iOS.
> > > >
> > > > Anyway, I would check that the following lines are being triggered:
> > > >
> > > > When starting:
> > > >
> > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798
> > > >
> > > > On connect:
> > > >
> > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741
> > > >
> > > > If those lines are not being triggered it is likely a client problem
> > > > which for some reason had not subscribed to received service changes
> > > > for some reason, if it doesn't subscribe to service changes then it
> > > > shall not cache any attribute and attempt to rediscover on every
> > > > connection.
> > > >
> > > > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > > > >
> > > > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > > > >
> > > > > Questions:
> > > > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > > > 3. Is there anything else we should look into?
> > > > >
> > > > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > > > >
> > > > > Thanks!
> > > > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> > > >
> > > >
> > > >
> > > > --
> > > > Luiz Augusto von Dentz
>
>
>
> --
> Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-16  0:20           ` Kenny Bian
@ 2021-04-16  0:49             ` Luiz Augusto von Dentz
  2021-04-16  3:06               ` Kenny Bian
  0 siblings, 1 reply; 13+ messages in thread
From: Luiz Augusto von Dentz @ 2021-04-16  0:49 UTC (permalink / raw)
  To: Kenny Bian; +Cc: Jamie Mccrae, linux-bluetooth

Hi Kenny,

On Thu, Apr 15, 2021 at 5:21 PM Kenny Bian <kennybian@gmail.com> wrote:
>
> Hi Luiz,
>
> Thank you so much. I appreciate it.
>
> That was my bad. I just checked. Our system is Ubuntu 18.04. The BlueZ
> version is "5.48-0ubuntu3.4" which is different from the versions in
> http://www.bluez.org/. I'm trying to figure out if this version
> includes the version 5.50. Do you know the corresponding BlueZ version
> for "5.48-0ubuntu3.4"?

5.48, which was the version available in 2018, more than 3 years/10
releases ago, a lot of things have been fixed over this time so Id
really recommend to upgrade to the latest if you want to have some
support.

> Thanks!
> Kenny
>
> On Thu, Apr 15, 2021 at 1:31 PM Luiz Augusto von Dentz
> <luiz.dentz@gmail.com> wrote:
> >
> > Hi Kenny,
> >
> > On Wed, Apr 14, 2021 at 10:44 PM Kenny Bian <kennybian@gmail.com> wrote:
> > >
> > > Hi Luiz,
> > >
> > > There is a UI example of nRF Connect which shows the "Service Changed
> > > Indication" is under "Generic
> > > Attribute"(http://forum.espruino.com/conversations/357737/). We're
> > > using BlueZ 5.48. I tried to add it by modifying example-gatt-server:
> >
> >
> > You should have mentioned that you are using 5.48, you need the following patch:
> >
> > commit a0b886e26c83ad4dfbf0b2b2e024c8ce9ead9a7d
> > Author: Szymon Janc <szymon.janc@codecoup.pl>
> > Date:   Wed Mar 28 12:10:55 2018 +0200
> >
> >     gatt: Add support for storing Service Changed CCC value
> >
> >     This adds support for storing CCC value of Service Changed
> >     characteristic. Once bluetoothd is restart stored values are read
> >     and any device subscribed to indications will receive Service Changed
> >     indication with 0x00010-0xffff value. This is to invalidate any
> >     non-core services since there is no way to verify if applications
> >     will register their services in same order (or at all).
> >
> >     This fix accessing invalid handles by stacks that rely only on Service
> >     Changed indication for rediscovery ie. Apple iOS.
> >
> > Or upgrade to a BlueZ release that has the above patch, which should be 5.50:
> >
> > +ver 5.50:
> > +       Fix issue with GATT and reading long values.
> > +       Fix issue with GATT and reading multiple includes.
> > +       Fix issue with GATT and service changes when offline.
> > +       Fix issue with handling secondary service discovery.
> > +       Fix issue with handling persistency of CCC values.
> >
> > >
> > > class ServiceChangedChrc(Characteristic):
> > >     SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'
> > >
> > >     def __init__(self, bus, index, service):
> > >         Characteristic.__init__(
> > >                 self, bus, index,
> > >                 self.SCI_UUID,
> > >                 ['indicate'],
> > >                 service)
> > >
> > >     def IndicateValue(self, options):
> > >         # This function doesn't exist. Just list it here.
> > >         pass
> > >
> > >
> > > class ServiceChangedService(Service):
> > >     MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'
> > >
> > >     def __init__(self, bus, index):
> > >         Service.__init__(self, bus, index, self.MY_UUID, True)
> > >         self.add_characteristic(ServiceChangedChrc(bus, 0, self))
> > >
> > >
> > > class Application(dbus.service.Object):
> > >     """
> > >     org.bluez.GattApplication1 interface implementation
> > >     """
> > >     def __init__(self, bus):
> > >         self.path = '/'
> > >         self.services = []
> > >         dbus.service.Object.__init__(self, bus, self.path)
> > >         self.add_service(HeartRateService(bus, 0))
> > >         self.add_service(BatteryService(bus, 1))
> > >         self.add_service(TestService(bus, 2))
> > >         self.add_service(ServiceChangedService(bus, 3))
> > >
> > >
> > > When I run it, there is "Failed to register application:
> > > org.bluez.Error.Failed: Failed to create entry in database". That is
> > > in the function client_ready_cb() in gatt-database.c in BlueZ code. Do
> > > you know how to fix it?
> >
> > You don't need to register Service Changed, the daemon already takes
> > care of registering it and there could only be one Service Changed in
> > the database.
> >
> > > Thanks!
> > > Kenny
> > >
> > > On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > >
> > > > Hi Jamie, Luiz,
> > > >
> > > > Thanks for your info.
> > > >
> > > > Luiz, to answer your questions:
> > > > BlueZ doesn't seem to emit "Service Changed Indication". Or it does
> > > > emit it, but we don't know how to verify it.
> > > > Yes, BlueZ acts as a GATT server which runs on Linux.
> > > >
> > > > So my questions:
> > > > How can I tell if "Service Changed Indication" is working? I need to
> > > > show it to our app developers that the GATT server does send the
> > > > "Service Changed Indication" when there is a service change.
> > > > By disabling the GATT's cache in "/etc/bluetooth/main.conf", the
> > > > "Service Changed Indication" is disabled?
> > > > Can "Service Changed Indication" be enabled in a conf file? Or should
> > > > it be done in the Python code? Could you please help find out that
> > > > info?
> > > > Our GATT server is based on the Python code
> > > > examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> > > > I don't know how to enable "Service Changed Indication" or "Robust
> > > > Caching" in Python code on the GATT server side. There is no document
> > > > or code samples about that. Please let me know if there is any
> > > > document or Python code example.
> > > >
> > > > Thanks!
> > > > Kenny
> > > >
> > > > On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
> > > > <luiz.dentz@gmail.com> wrote:
> > > > >
> > > > > Hi Jamie, Brian,
> > > > >
> > > > > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> > > > > <Jamie.Mccrae@lairdconnect.com> wrote:
> > > > > >
> > > > > > Hi Kenny,
> > > > > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> > > > >
> > > > > Yep, and while at it implement the so called Robust Caching feature so
> > > > > we can detect if anything has changed by reading the DB Hash.
> > > > >
> > > > > > Thanks,
> > > > > > Jamie
> > > > > >
> > > > > > -----Original Message-----
> > > > > > From: Kenny Bian <kennybian@gmail.com>
> > > > > > Sent: 13 April 2021 06:59
> > > > > > To: linux-bluetooth@vger.kernel.org
> > > > > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > > > > >
> > > > > > EXTERNAL EMAIL: Be careful with attachments and links.
> > > > > >
> > > > > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > > > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > > > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > > > > folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> > > > > > "/etc/bluetooth/main.conf":
> > > > > > [GATT]
> > > > > > Cache = no
> > > > >
> > > > > When you say the app can't handle changed service do you mean BlueZ
> > > > > doesn't emit changes to the attributes (via Service Changed) or is it
> > > > > really the application not being able to handle the changes?
> > > > >
> > > > > > But recently, we saw the problem again even if the bluetooth cache is
> > > > > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> > > > >
> > > > > So BlueZ is acting as the server, right? The Cache only applies to the
> > > > > client portion, there is no such thing as disabling the remote cache.
> > > > > I don't see any incoming Read By Group Request from the remote so it
> > > > > is very likely that it has cached the values, there is no Read By Type
> > > > > for the DB Hash either which is quite surprising to me since that is
> > > > > required for stacks supporting Robust Caching which I believe is the
> > > > > case of iOS.
> > > > >
> > > > > Anyway, I would check that the following lines are being triggered:
> > > > >
> > > > > When starting:
> > > > >
> > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798
> > > > >
> > > > > On connect:
> > > > >
> > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741
> > > > >
> > > > > If those lines are not being triggered it is likely a client problem
> > > > > which for some reason had not subscribed to received service changes
> > > > > for some reason, if it doesn't subscribe to service changes then it
> > > > > shall not cache any attribute and attempt to rediscover on every
> > > > > connection.
> > > > >
> > > > > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > > > > >
> > > > > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > > > > >
> > > > > > Questions:
> > > > > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > > > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > > > > 3. Is there anything else we should look into?
> > > > > >
> > > > > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > > > > >
> > > > > > Thanks!
> > > > > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> > > > >
> > > > >
> > > > >
> > > > > --
> > > > > Luiz Augusto von Dentz
> >
> >
> >
> > --
> > Luiz Augusto von Dentz



-- 
Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-16  0:49             ` Luiz Augusto von Dentz
@ 2021-04-16  3:06               ` Kenny Bian
  2021-04-16  4:03                 ` Kenny Bian
  0 siblings, 1 reply; 13+ messages in thread
From: Kenny Bian @ 2021-04-16  3:06 UTC (permalink / raw)
  To: Luiz Augusto von Dentz; +Cc: Jamie Mccrae, linux-bluetooth

Hi Luiz,

Thank you so much! You're absolutely right.

I'll talk to our team to upgrade our Ubuntu to 20.04 LTS. Then I'll
test the BlueZ 5.53 which is the latest version on Ubuntu 20.04 LTS.

Thanks again!
Kenny

On Thu, Apr 15, 2021 at 5:49 PM Luiz Augusto von Dentz
<luiz.dentz@gmail.com> wrote:
>
> Hi Kenny,
>
> On Thu, Apr 15, 2021 at 5:21 PM Kenny Bian <kennybian@gmail.com> wrote:
> >
> > Hi Luiz,
> >
> > Thank you so much. I appreciate it.
> >
> > That was my bad. I just checked. Our system is Ubuntu 18.04. The BlueZ
> > version is "5.48-0ubuntu3.4" which is different from the versions in
> > http://www.bluez.org/. I'm trying to figure out if this version
> > includes the version 5.50. Do you know the corresponding BlueZ version
> > for "5.48-0ubuntu3.4"?
>
> 5.48, which was the version available in 2018, more than 3 years/10
> releases ago, a lot of things have been fixed over this time so Id
> really recommend to upgrade to the latest if you want to have some
> support.
>
> > Thanks!
> > Kenny
> >
> > On Thu, Apr 15, 2021 at 1:31 PM Luiz Augusto von Dentz
> > <luiz.dentz@gmail.com> wrote:
> > >
> > > Hi Kenny,
> > >
> > > On Wed, Apr 14, 2021 at 10:44 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > >
> > > > Hi Luiz,
> > > >
> > > > There is a UI example of nRF Connect which shows the "Service Changed
> > > > Indication" is under "Generic
> > > > Attribute"(http://forum.espruino.com/conversations/357737/). We're
> > > > using BlueZ 5.48. I tried to add it by modifying example-gatt-server:
> > >
> > >
> > > You should have mentioned that you are using 5.48, you need the following patch:
> > >
> > > commit a0b886e26c83ad4dfbf0b2b2e024c8ce9ead9a7d
> > > Author: Szymon Janc <szymon.janc@codecoup.pl>
> > > Date:   Wed Mar 28 12:10:55 2018 +0200
> > >
> > >     gatt: Add support for storing Service Changed CCC value
> > >
> > >     This adds support for storing CCC value of Service Changed
> > >     characteristic. Once bluetoothd is restart stored values are read
> > >     and any device subscribed to indications will receive Service Changed
> > >     indication with 0x00010-0xffff value. This is to invalidate any
> > >     non-core services since there is no way to verify if applications
> > >     will register their services in same order (or at all).
> > >
> > >     This fix accessing invalid handles by stacks that rely only on Service
> > >     Changed indication for rediscovery ie. Apple iOS.
> > >
> > > Or upgrade to a BlueZ release that has the above patch, which should be 5.50:
> > >
> > > +ver 5.50:
> > > +       Fix issue with GATT and reading long values.
> > > +       Fix issue with GATT and reading multiple includes.
> > > +       Fix issue with GATT and service changes when offline.
> > > +       Fix issue with handling secondary service discovery.
> > > +       Fix issue with handling persistency of CCC values.
> > >
> > > >
> > > > class ServiceChangedChrc(Characteristic):
> > > >     SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'
> > > >
> > > >     def __init__(self, bus, index, service):
> > > >         Characteristic.__init__(
> > > >                 self, bus, index,
> > > >                 self.SCI_UUID,
> > > >                 ['indicate'],
> > > >                 service)
> > > >
> > > >     def IndicateValue(self, options):
> > > >         # This function doesn't exist. Just list it here.
> > > >         pass
> > > >
> > > >
> > > > class ServiceChangedService(Service):
> > > >     MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'
> > > >
> > > >     def __init__(self, bus, index):
> > > >         Service.__init__(self, bus, index, self.MY_UUID, True)
> > > >         self.add_characteristic(ServiceChangedChrc(bus, 0, self))
> > > >
> > > >
> > > > class Application(dbus.service.Object):
> > > >     """
> > > >     org.bluez.GattApplication1 interface implementation
> > > >     """
> > > >     def __init__(self, bus):
> > > >         self.path = '/'
> > > >         self.services = []
> > > >         dbus.service.Object.__init__(self, bus, self.path)
> > > >         self.add_service(HeartRateService(bus, 0))
> > > >         self.add_service(BatteryService(bus, 1))
> > > >         self.add_service(TestService(bus, 2))
> > > >         self.add_service(ServiceChangedService(bus, 3))
> > > >
> > > >
> > > > When I run it, there is "Failed to register application:
> > > > org.bluez.Error.Failed: Failed to create entry in database". That is
> > > > in the function client_ready_cb() in gatt-database.c in BlueZ code. Do
> > > > you know how to fix it?
> > >
> > > You don't need to register Service Changed, the daemon already takes
> > > care of registering it and there could only be one Service Changed in
> > > the database.
> > >
> > > > Thanks!
> > > > Kenny
> > > >
> > > > On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > > >
> > > > > Hi Jamie, Luiz,
> > > > >
> > > > > Thanks for your info.
> > > > >
> > > > > Luiz, to answer your questions:
> > > > > BlueZ doesn't seem to emit "Service Changed Indication". Or it does
> > > > > emit it, but we don't know how to verify it.
> > > > > Yes, BlueZ acts as a GATT server which runs on Linux.
> > > > >
> > > > > So my questions:
> > > > > How can I tell if "Service Changed Indication" is working? I need to
> > > > > show it to our app developers that the GATT server does send the
> > > > > "Service Changed Indication" when there is a service change.
> > > > > By disabling the GATT's cache in "/etc/bluetooth/main.conf", the
> > > > > "Service Changed Indication" is disabled?
> > > > > Can "Service Changed Indication" be enabled in a conf file? Or should
> > > > > it be done in the Python code? Could you please help find out that
> > > > > info?
> > > > > Our GATT server is based on the Python code
> > > > > examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> > > > > I don't know how to enable "Service Changed Indication" or "Robust
> > > > > Caching" in Python code on the GATT server side. There is no document
> > > > > or code samples about that. Please let me know if there is any
> > > > > document or Python code example.
> > > > >
> > > > > Thanks!
> > > > > Kenny
> > > > >
> > > > > On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
> > > > > <luiz.dentz@gmail.com> wrote:
> > > > > >
> > > > > > Hi Jamie, Brian,
> > > > > >
> > > > > > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> > > > > > <Jamie.Mccrae@lairdconnect.com> wrote:
> > > > > > >
> > > > > > > Hi Kenny,
> > > > > > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> > > > > >
> > > > > > Yep, and while at it implement the so called Robust Caching feature so
> > > > > > we can detect if anything has changed by reading the DB Hash.
> > > > > >
> > > > > > > Thanks,
> > > > > > > Jamie
> > > > > > >
> > > > > > > -----Original Message-----
> > > > > > > From: Kenny Bian <kennybian@gmail.com>
> > > > > > > Sent: 13 April 2021 06:59
> > > > > > > To: linux-bluetooth@vger.kernel.org
> > > > > > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > > > > > >
> > > > > > > EXTERNAL EMAIL: Be careful with attachments and links.
> > > > > > >
> > > > > > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > > > > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > > > > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > > > > > folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> > > > > > > "/etc/bluetooth/main.conf":
> > > > > > > [GATT]
> > > > > > > Cache = no
> > > > > >
> > > > > > When you say the app can't handle changed service do you mean BlueZ
> > > > > > doesn't emit changes to the attributes (via Service Changed) or is it
> > > > > > really the application not being able to handle the changes?
> > > > > >
> > > > > > > But recently, we saw the problem again even if the bluetooth cache is
> > > > > > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> > > > > >
> > > > > > So BlueZ is acting as the server, right? The Cache only applies to the
> > > > > > client portion, there is no such thing as disabling the remote cache.
> > > > > > I don't see any incoming Read By Group Request from the remote so it
> > > > > > is very likely that it has cached the values, there is no Read By Type
> > > > > > for the DB Hash either which is quite surprising to me since that is
> > > > > > required for stacks supporting Robust Caching which I believe is the
> > > > > > case of iOS.
> > > > > >
> > > > > > Anyway, I would check that the following lines are being triggered:
> > > > > >
> > > > > > When starting:
> > > > > >
> > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798
> > > > > >
> > > > > > On connect:
> > > > > >
> > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741
> > > > > >
> > > > > > If those lines are not being triggered it is likely a client problem
> > > > > > which for some reason had not subscribed to received service changes
> > > > > > for some reason, if it doesn't subscribe to service changes then it
> > > > > > shall not cache any attribute and attempt to rediscover on every
> > > > > > connection.
> > > > > >
> > > > > > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > > > > > >
> > > > > > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > > > > > >
> > > > > > > Questions:
> > > > > > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > > > > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > > > > > 3. Is there anything else we should look into?
> > > > > > >
> > > > > > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > > > > > >
> > > > > > > Thanks!
> > > > > > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> > > > > >
> > > > > >
> > > > > >
> > > > > > --
> > > > > > Luiz Augusto von Dentz
> > >
> > >
> > >
> > > --
> > > Luiz Augusto von Dentz
>
>
>
> --
> Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-16  3:06               ` Kenny Bian
@ 2021-04-16  4:03                 ` Kenny Bian
  2021-04-16  6:34                   ` Jamie Mccrae
  0 siblings, 1 reply; 13+ messages in thread
From: Kenny Bian @ 2021-04-16  4:03 UTC (permalink / raw)
  To: Luiz Augusto von Dentz; +Cc: Jamie Mccrae, linux-bluetooth

Hi Luiz,

One more question. Once we upgrade our device to Ubuntu 20.04 LTS with
BlueZ 5.53, we'll test "Service Changed Indication". Is GATT cache
related to "Service Changed Indication"? If they are related, then I
guess we should turn on the GATT cache in /etc/bluetooth/main.conf?
Right now, the GATT cache is turned off in our device.

Thanks,
Kenny

On Thu, Apr 15, 2021 at 8:06 PM Kenny Bian <kennybian@gmail.com> wrote:
>
> Hi Luiz,
>
> Thank you so much! You're absolutely right.
>
> I'll talk to our team to upgrade our Ubuntu to 20.04 LTS. Then I'll
> test the BlueZ 5.53 which is the latest version on Ubuntu 20.04 LTS.
>
> Thanks again!
> Kenny
>
> On Thu, Apr 15, 2021 at 5:49 PM Luiz Augusto von Dentz
> <luiz.dentz@gmail.com> wrote:
> >
> > Hi Kenny,
> >
> > On Thu, Apr 15, 2021 at 5:21 PM Kenny Bian <kennybian@gmail.com> wrote:
> > >
> > > Hi Luiz,
> > >
> > > Thank you so much. I appreciate it.
> > >
> > > That was my bad. I just checked. Our system is Ubuntu 18.04. The BlueZ
> > > version is "5.48-0ubuntu3.4" which is different from the versions in
> > > http://www.bluez.org/. I'm trying to figure out if this version
> > > includes the version 5.50. Do you know the corresponding BlueZ version
> > > for "5.48-0ubuntu3.4"?
> >
> > 5.48, which was the version available in 2018, more than 3 years/10
> > releases ago, a lot of things have been fixed over this time so Id
> > really recommend to upgrade to the latest if you want to have some
> > support.
> >
> > > Thanks!
> > > Kenny
> > >
> > > On Thu, Apr 15, 2021 at 1:31 PM Luiz Augusto von Dentz
> > > <luiz.dentz@gmail.com> wrote:
> > > >
> > > > Hi Kenny,
> > > >
> > > > On Wed, Apr 14, 2021 at 10:44 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > > >
> > > > > Hi Luiz,
> > > > >
> > > > > There is a UI example of nRF Connect which shows the "Service Changed
> > > > > Indication" is under "Generic
> > > > > Attribute"(http://forum.espruino.com/conversations/357737/). We're
> > > > > using BlueZ 5.48. I tried to add it by modifying example-gatt-server:
> > > >
> > > >
> > > > You should have mentioned that you are using 5.48, you need the following patch:
> > > >
> > > > commit a0b886e26c83ad4dfbf0b2b2e024c8ce9ead9a7d
> > > > Author: Szymon Janc <szymon.janc@codecoup.pl>
> > > > Date:   Wed Mar 28 12:10:55 2018 +0200
> > > >
> > > >     gatt: Add support for storing Service Changed CCC value
> > > >
> > > >     This adds support for storing CCC value of Service Changed
> > > >     characteristic. Once bluetoothd is restart stored values are read
> > > >     and any device subscribed to indications will receive Service Changed
> > > >     indication with 0x00010-0xffff value. This is to invalidate any
> > > >     non-core services since there is no way to verify if applications
> > > >     will register their services in same order (or at all).
> > > >
> > > >     This fix accessing invalid handles by stacks that rely only on Service
> > > >     Changed indication for rediscovery ie. Apple iOS.
> > > >
> > > > Or upgrade to a BlueZ release that has the above patch, which should be 5.50:
> > > >
> > > > +ver 5.50:
> > > > +       Fix issue with GATT and reading long values.
> > > > +       Fix issue with GATT and reading multiple includes.
> > > > +       Fix issue with GATT and service changes when offline.
> > > > +       Fix issue with handling secondary service discovery.
> > > > +       Fix issue with handling persistency of CCC values.
> > > >
> > > > >
> > > > > class ServiceChangedChrc(Characteristic):
> > > > >     SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'
> > > > >
> > > > >     def __init__(self, bus, index, service):
> > > > >         Characteristic.__init__(
> > > > >                 self, bus, index,
> > > > >                 self.SCI_UUID,
> > > > >                 ['indicate'],
> > > > >                 service)
> > > > >
> > > > >     def IndicateValue(self, options):
> > > > >         # This function doesn't exist. Just list it here.
> > > > >         pass
> > > > >
> > > > >
> > > > > class ServiceChangedService(Service):
> > > > >     MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'
> > > > >
> > > > >     def __init__(self, bus, index):
> > > > >         Service.__init__(self, bus, index, self.MY_UUID, True)
> > > > >         self.add_characteristic(ServiceChangedChrc(bus, 0, self))
> > > > >
> > > > >
> > > > > class Application(dbus.service.Object):
> > > > >     """
> > > > >     org.bluez.GattApplication1 interface implementation
> > > > >     """
> > > > >     def __init__(self, bus):
> > > > >         self.path = '/'
> > > > >         self.services = []
> > > > >         dbus.service.Object.__init__(self, bus, self.path)
> > > > >         self.add_service(HeartRateService(bus, 0))
> > > > >         self.add_service(BatteryService(bus, 1))
> > > > >         self.add_service(TestService(bus, 2))
> > > > >         self.add_service(ServiceChangedService(bus, 3))
> > > > >
> > > > >
> > > > > When I run it, there is "Failed to register application:
> > > > > org.bluez.Error.Failed: Failed to create entry in database". That is
> > > > > in the function client_ready_cb() in gatt-database.c in BlueZ code. Do
> > > > > you know how to fix it?
> > > >
> > > > You don't need to register Service Changed, the daemon already takes
> > > > care of registering it and there could only be one Service Changed in
> > > > the database.
> > > >
> > > > > Thanks!
> > > > > Kenny
> > > > >
> > > > > On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > > > >
> > > > > > Hi Jamie, Luiz,
> > > > > >
> > > > > > Thanks for your info.
> > > > > >
> > > > > > Luiz, to answer your questions:
> > > > > > BlueZ doesn't seem to emit "Service Changed Indication". Or it does
> > > > > > emit it, but we don't know how to verify it.
> > > > > > Yes, BlueZ acts as a GATT server which runs on Linux.
> > > > > >
> > > > > > So my questions:
> > > > > > How can I tell if "Service Changed Indication" is working? I need to
> > > > > > show it to our app developers that the GATT server does send the
> > > > > > "Service Changed Indication" when there is a service change.
> > > > > > By disabling the GATT's cache in "/etc/bluetooth/main.conf", the
> > > > > > "Service Changed Indication" is disabled?
> > > > > > Can "Service Changed Indication" be enabled in a conf file? Or should
> > > > > > it be done in the Python code? Could you please help find out that
> > > > > > info?
> > > > > > Our GATT server is based on the Python code
> > > > > > examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> > > > > > I don't know how to enable "Service Changed Indication" or "Robust
> > > > > > Caching" in Python code on the GATT server side. There is no document
> > > > > > or code samples about that. Please let me know if there is any
> > > > > > document or Python code example.
> > > > > >
> > > > > > Thanks!
> > > > > > Kenny
> > > > > >
> > > > > > On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
> > > > > > <luiz.dentz@gmail.com> wrote:
> > > > > > >
> > > > > > > Hi Jamie, Brian,
> > > > > > >
> > > > > > > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> > > > > > > <Jamie.Mccrae@lairdconnect.com> wrote:
> > > > > > > >
> > > > > > > > Hi Kenny,
> > > > > > > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> > > > > > >
> > > > > > > Yep, and while at it implement the so called Robust Caching feature so
> > > > > > > we can detect if anything has changed by reading the DB Hash.
> > > > > > >
> > > > > > > > Thanks,
> > > > > > > > Jamie
> > > > > > > >
> > > > > > > > -----Original Message-----
> > > > > > > > From: Kenny Bian <kennybian@gmail.com>
> > > > > > > > Sent: 13 April 2021 06:59
> > > > > > > > To: linux-bluetooth@vger.kernel.org
> > > > > > > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > > > > > > >
> > > > > > > > EXTERNAL EMAIL: Be careful with attachments and links.
> > > > > > > >
> > > > > > > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > > > > > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > > > > > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > > > > > > folder is copied over to the new build's partition. We realized that there is no "service changed indication". The app can't handle the changed services. So we disabled the bluetooth cache by set this in
> > > > > > > > "/etc/bluetooth/main.conf":
> > > > > > > > [GATT]
> > > > > > > > Cache = no
> > > > > > >
> > > > > > > When you say the app can't handle changed service do you mean BlueZ
> > > > > > > doesn't emit changes to the attributes (via Service Changed) or is it
> > > > > > > really the application not being able to handle the changes?
> > > > > > >
> > > > > > > > But recently, we saw the problem again even if the bluetooth cache is
> > > > > > > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> > > > > > >
> > > > > > > So BlueZ is acting as the server, right? The Cache only applies to the
> > > > > > > client portion, there is no such thing as disabling the remote cache.
> > > > > > > I don't see any incoming Read By Group Request from the remote so it
> > > > > > > is very likely that it has cached the values, there is no Read By Type
> > > > > > > for the DB Hash either which is quite surprising to me since that is
> > > > > > > required for stacks supporting Robust Caching which I believe is the
> > > > > > > case of iOS.
> > > > > > >
> > > > > > > Anyway, I would check that the following lines are being triggered:
> > > > > > >
> > > > > > > When starting:
> > > > > > >
> > > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3798
> > > > > > >
> > > > > > > On connect:
> > > > > > >
> > > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/src/gatt-database.c#n3741
> > > > > > >
> > > > > > > If those lines are not being triggered it is likely a client problem
> > > > > > > which for some reason had not subscribed to received service changes
> > > > > > > for some reason, if it doesn't subscribe to service changes then it
> > > > > > > shall not cache any attribute and attempt to rediscover on every
> > > > > > > connection.
> > > > > > >
> > > > > > > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > > > > > > >
> > > > > > > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > > > > > > >
> > > > > > > > Questions:
> > > > > > > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > > > > > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > > > > > > 3. Is there anything else we should look into?
> > > > > > > >
> > > > > > > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > > > > > > >
> > > > > > > > Thanks!
> > > > > > > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > > --
> > > > > > > Luiz Augusto von Dentz
> > > >
> > > >
> > > >
> > > > --
> > > > Luiz Augusto von Dentz
> >
> >
> >
> > --
> > Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* RE: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-16  4:03                 ` Kenny Bian
@ 2021-04-16  6:34                   ` Jamie Mccrae
  2021-04-20 21:35                     ` Kenny Bian
  0 siblings, 1 reply; 13+ messages in thread
From: Jamie Mccrae @ 2021-04-16  6:34 UTC (permalink / raw)
  To: Kenny Bian, Luiz Augusto von Dentz; +Cc: linux-bluetooth

Hi Kenny,
The way it works is when a device connects (it might just be a normal connection, it might be only if it pairs, it's vender specific) it will generally cache the GATT table of the remote device, this is so that future connections are faster as it won't need to send multiple read commands to get it. The easy way for that device to know if the GATT table has changed is it uses a specific GATT attribute with a GATT table hash and reads that, if it's changed then it needs to clear the cache and re-read the table. That only works when a device connects and reads it, if the GATT table is updated during a connection, then an indication can be sent to that device telling it the GATT table hash has changed and it can re-read it and clear it during a connection.
If you are connecting a phone to your embedded device with the GATT table being on the embedded device then the cache is stored on the phone, there doesn't need to be a GATT table hash on the embedded device because the phone doesn't have a GATT table and iOS/android will create the cache themselves, you cannot disable that from the embedded device side, whatever cache you enable/disable on the embedded system is for that system only, it does not propagate that configuration value to other devices.
Thanks,
Jamie

-----Original Message-----
From: Kenny Bian <kennybian@gmail.com> 
Sent: 16 April 2021 05:03
To: Luiz Augusto von Dentz <luiz.dentz@gmail.com>
Cc: Jamie Mccrae <Jamie.Mccrae@lairdconnect.com>; linux-bluetooth@vger.kernel.org
Subject: Re: Disabled bluetooth cache. But the app still getting wrong data?

EXTERNAL EMAIL: Be careful with attachments and links.

Hi Luiz,

One more question. Once we upgrade our device to Ubuntu 20.04 LTS with BlueZ 5.53, we'll test "Service Changed Indication". Is GATT cache related to "Service Changed Indication"? If they are related, then I guess we should turn on the GATT cache in /etc/bluetooth/main.conf?
Right now, the GATT cache is turned off in our device.

Thanks,
Kenny

On Thu, Apr 15, 2021 at 8:06 PM Kenny Bian <kennybian@gmail.com> wrote:
>
> Hi Luiz,
>
> Thank you so much! You're absolutely right.
>
> I'll talk to our team to upgrade our Ubuntu to 20.04 LTS. Then I'll 
> test the BlueZ 5.53 which is the latest version on Ubuntu 20.04 LTS.
>
> Thanks again!
> Kenny
>
> On Thu, Apr 15, 2021 at 5:49 PM Luiz Augusto von Dentz 
> <luiz.dentz@gmail.com> wrote:
> >
> > Hi Kenny,
> >
> > On Thu, Apr 15, 2021 at 5:21 PM Kenny Bian <kennybian@gmail.com> wrote:
> > >
> > > Hi Luiz,
> > >
> > > Thank you so much. I appreciate it.
> > >
> > > That was my bad. I just checked. Our system is Ubuntu 18.04. The 
> > > BlueZ version is "5.48-0ubuntu3.4" which is different from the 
> > > versions in http://www.bluez.org/. I'm trying to figure out if 
> > > this version includes the version 5.50. Do you know the 
> > > corresponding BlueZ version for "5.48-0ubuntu3.4"?
> >
> > 5.48, which was the version available in 2018, more than 3 years/10 
> > releases ago, a lot of things have been fixed over this time so Id 
> > really recommend to upgrade to the latest if you want to have some 
> > support.
> >
> > > Thanks!
> > > Kenny
> > >
> > > On Thu, Apr 15, 2021 at 1:31 PM Luiz Augusto von Dentz 
> > > <luiz.dentz@gmail.com> wrote:
> > > >
> > > > Hi Kenny,
> > > >
> > > > On Wed, Apr 14, 2021 at 10:44 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > > >
> > > > > Hi Luiz,
> > > > >
> > > > > There is a UI example of nRF Connect which shows the "Service 
> > > > > Changed Indication" is under "Generic 
> > > > > Attribute"(http://forum.espruino.com/conversations/357737/). 
> > > > > We're using BlueZ 5.48. I tried to add it by modifying example-gatt-server:
> > > >
> > > >
> > > > You should have mentioned that you are using 5.48, you need the following patch:
> > > >
> > > > commit a0b886e26c83ad4dfbf0b2b2e024c8ce9ead9a7d
> > > > Author: Szymon Janc <szymon.janc@codecoup.pl>
> > > > Date:   Wed Mar 28 12:10:55 2018 +0200
> > > >
> > > >     gatt: Add support for storing Service Changed CCC value
> > > >
> > > >     This adds support for storing CCC value of Service Changed
> > > >     characteristic. Once bluetoothd is restart stored values are read
> > > >     and any device subscribed to indications will receive Service Changed
> > > >     indication with 0x00010-0xffff value. This is to invalidate any
> > > >     non-core services since there is no way to verify if applications
> > > >     will register their services in same order (or at all).
> > > >
> > > >     This fix accessing invalid handles by stacks that rely only on Service
> > > >     Changed indication for rediscovery ie. Apple iOS.
> > > >
> > > > Or upgrade to a BlueZ release that has the above patch, which should be 5.50:
> > > >
> > > > +ver 5.50:
> > > > +       Fix issue with GATT and reading long values.
> > > > +       Fix issue with GATT and reading multiple includes.
> > > > +       Fix issue with GATT and service changes when offline.
> > > > +       Fix issue with handling secondary service discovery.
> > > > +       Fix issue with handling persistency of CCC values.
> > > >
> > > > >
> > > > > class ServiceChangedChrc(Characteristic):
> > > > >     SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'
> > > > >
> > > > >     def __init__(self, bus, index, service):
> > > > >         Characteristic.__init__(
> > > > >                 self, bus, index,
> > > > >                 self.SCI_UUID,
> > > > >                 ['indicate'],
> > > > >                 service)
> > > > >
> > > > >     def IndicateValue(self, options):
> > > > >         # This function doesn't exist. Just list it here.
> > > > >         pass
> > > > >
> > > > >
> > > > > class ServiceChangedService(Service):
> > > > >     MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'
> > > > >
> > > > >     def __init__(self, bus, index):
> > > > >         Service.__init__(self, bus, index, self.MY_UUID, True)
> > > > >         self.add_characteristic(ServiceChangedChrc(bus, 0, 
> > > > > self))
> > > > >
> > > > >
> > > > > class Application(dbus.service.Object):
> > > > >     """
> > > > >     org.bluez.GattApplication1 interface implementation
> > > > >     """
> > > > >     def __init__(self, bus):
> > > > >         self.path = '/'
> > > > >         self.services = []
> > > > >         dbus.service.Object.__init__(self, bus, self.path)
> > > > >         self.add_service(HeartRateService(bus, 0))
> > > > >         self.add_service(BatteryService(bus, 1))
> > > > >         self.add_service(TestService(bus, 2))
> > > > >         self.add_service(ServiceChangedService(bus, 3))
> > > > >
> > > > >
> > > > > When I run it, there is "Failed to register application:
> > > > > org.bluez.Error.Failed: Failed to create entry in database". 
> > > > > That is in the function client_ready_cb() in gatt-database.c 
> > > > > in BlueZ code. Do you know how to fix it?
> > > >
> > > > You don't need to register Service Changed, the daemon already 
> > > > takes care of registering it and there could only be one Service 
> > > > Changed in the database.
> > > >
> > > > > Thanks!
> > > > > Kenny
> > > > >
> > > > > On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > > > >
> > > > > > Hi Jamie, Luiz,
> > > > > >
> > > > > > Thanks for your info.
> > > > > >
> > > > > > Luiz, to answer your questions:
> > > > > > BlueZ doesn't seem to emit "Service Changed Indication". Or 
> > > > > > it does emit it, but we don't know how to verify it.
> > > > > > Yes, BlueZ acts as a GATT server which runs on Linux.
> > > > > >
> > > > > > So my questions:
> > > > > > How can I tell if "Service Changed Indication" is working? I 
> > > > > > need to show it to our app developers that the GATT server 
> > > > > > does send the "Service Changed Indication" when there is a service change.
> > > > > > By disabling the GATT's cache in "/etc/bluetooth/main.conf", 
> > > > > > the "Service Changed Indication" is disabled?
> > > > > > Can "Service Changed Indication" be enabled in a conf file? 
> > > > > > Or should it be done in the Python code? Could you please 
> > > > > > help find out that info?
> > > > > > Our GATT server is based on the Python code 
> > > > > > examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> > > > > > I don't know how to enable "Service Changed Indication" or 
> > > > > > "Robust Caching" in Python code on the GATT server side. 
> > > > > > There is no document or code samples about that. Please let 
> > > > > > me know if there is any document or Python code example.
> > > > > >
> > > > > > Thanks!
> > > > > > Kenny
> > > > > >
> > > > > > On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz 
> > > > > > <luiz.dentz@gmail.com> wrote:
> > > > > > >
> > > > > > > Hi Jamie, Brian,
> > > > > > >
> > > > > > > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae 
> > > > > > > <Jamie.Mccrae@lairdconnect.com> wrote:
> > > > > > > >
> > > > > > > > Hi Kenny,
> > > > > > > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> > > > > > >
> > > > > > > Yep, and while at it implement the so called Robust 
> > > > > > > Caching feature so we can detect if anything has changed by reading the DB Hash.
> > > > > > >
> > > > > > > > Thanks,
> > > > > > > > Jamie
> > > > > > > >
> > > > > > > > -----Original Message-----
> > > > > > > > From: Kenny Bian <kennybian@gmail.com>
> > > > > > > > Sent: 13 April 2021 06:59
> > > > > > > > To: linux-bluetooth@vger.kernel.org
> > > > > > > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > > > > > > >
> > > > > > > > EXTERNAL EMAIL: Be careful with attachments and links.
> > > > > > > >
> > > > > > > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > > > > > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > > > > > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > > > > > > folder is copied over to the new build's partition. We 
> > > > > > > > realized that there is no "service changed indication". 
> > > > > > > > The app can't handle the changed services. So we 
> > > > > > > > disabled the bluetooth cache by set this in
> > > > > > > > "/etc/bluetooth/main.conf":
> > > > > > > > [GATT]
> > > > > > > > Cache = no
> > > > > > >
> > > > > > > When you say the app can't handle changed service do you 
> > > > > > > mean BlueZ doesn't emit changes to the attributes (via 
> > > > > > > Service Changed) or is it really the application not being able to handle the changes?
> > > > > > >
> > > > > > > > But recently, we saw the problem again even if the 
> > > > > > > > bluetooth cache is
> > > > > > > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> > > > > > >
> > > > > > > So BlueZ is acting as the server, right? The Cache only 
> > > > > > > applies to the client portion, there is no such thing as disabling the remote cache.
> > > > > > > I don't see any incoming Read By Group Request from the 
> > > > > > > remote so it is very likely that it has cached the values, 
> > > > > > > there is no Read By Type for the DB Hash either which is 
> > > > > > > quite surprising to me since that is required for stacks 
> > > > > > > supporting Robust Caching which I believe is the case of iOS.
> > > > > > >
> > > > > > > Anyway, I would check that the following lines are being triggered:
> > > > > > >
> > > > > > > When starting:
> > > > > > >
> > > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/sr
> > > > > > > c/gatt-database.c#n3798
> > > > > > >
> > > > > > > On connect:
> > > > > > >
> > > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/sr
> > > > > > > c/gatt-database.c#n3741
> > > > > > >
> > > > > > > If those lines are not being triggered it is likely a 
> > > > > > > client problem which for some reason had not subscribed to 
> > > > > > > received service changes for some reason, if it doesn't 
> > > > > > > subscribe to service changes then it shall not cache any 
> > > > > > > attribute and attempt to rediscover on every connection.
> > > > > > >
> > > > > > > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > > > > > > >
> > > > > > > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > > > > > > >
> > > > > > > > Questions:
> > > > > > > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > > > > > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > > > > > > 3. Is there anything else we should look into?
> > > > > > > >
> > > > > > > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > > > > > > >
> > > > > > > > Thanks!
> > > > > > > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > > --
> > > > > > > Luiz Augusto von Dentz
> > > >
> > > >
> > > >
> > > > --
> > > > Luiz Augusto von Dentz
> >
> >
> >
> > --
> > Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: Disabled bluetooth cache. But the app still getting wrong data?
  2021-04-16  6:34                   ` Jamie Mccrae
@ 2021-04-20 21:35                     ` Kenny Bian
  0 siblings, 0 replies; 13+ messages in thread
From: Kenny Bian @ 2021-04-20 21:35 UTC (permalink / raw)
  To: Jamie Mccrae; +Cc: Luiz Augusto von Dentz, linux-bluetooth

Thank you so much, Jamie. That well explained it.

On Thu, Apr 15, 2021 at 11:34 PM Jamie Mccrae
<Jamie.Mccrae@lairdconnect.com> wrote:
>
> Hi Kenny,
> The way it works is when a device connects (it might just be a normal connection, it might be only if it pairs, it's vender specific) it will generally cache the GATT table of the remote device, this is so that future connections are faster as it won't need to send multiple read commands to get it. The easy way for that device to know if the GATT table has changed is it uses a specific GATT attribute with a GATT table hash and reads that, if it's changed then it needs to clear the cache and re-read the table. That only works when a device connects and reads it, if the GATT table is updated during a connection, then an indication can be sent to that device telling it the GATT table hash has changed and it can re-read it and clear it during a connection.
> If you are connecting a phone to your embedded device with the GATT table being on the embedded device then the cache is stored on the phone, there doesn't need to be a GATT table hash on the embedded device because the phone doesn't have a GATT table and iOS/android will create the cache themselves, you cannot disable that from the embedded device side, whatever cache you enable/disable on the embedded system is for that system only, it does not propagate that configuration value to other devices.
> Thanks,
> Jamie
>
> -----Original Message-----
> From: Kenny Bian <kennybian@gmail.com>
> Sent: 16 April 2021 05:03
> To: Luiz Augusto von Dentz <luiz.dentz@gmail.com>
> Cc: Jamie Mccrae <Jamie.Mccrae@lairdconnect.com>; linux-bluetooth@vger.kernel.org
> Subject: Re: Disabled bluetooth cache. But the app still getting wrong data?
>
> EXTERNAL EMAIL: Be careful with attachments and links.
>
> Hi Luiz,
>
> One more question. Once we upgrade our device to Ubuntu 20.04 LTS with BlueZ 5.53, we'll test "Service Changed Indication". Is GATT cache related to "Service Changed Indication"? If they are related, then I guess we should turn on the GATT cache in /etc/bluetooth/main.conf?
> Right now, the GATT cache is turned off in our device.
>
> Thanks,
> Kenny
>
> On Thu, Apr 15, 2021 at 8:06 PM Kenny Bian <kennybian@gmail.com> wrote:
> >
> > Hi Luiz,
> >
> > Thank you so much! You're absolutely right.
> >
> > I'll talk to our team to upgrade our Ubuntu to 20.04 LTS. Then I'll
> > test the BlueZ 5.53 which is the latest version on Ubuntu 20.04 LTS.
> >
> > Thanks again!
> > Kenny
> >
> > On Thu, Apr 15, 2021 at 5:49 PM Luiz Augusto von Dentz
> > <luiz.dentz@gmail.com> wrote:
> > >
> > > Hi Kenny,
> > >
> > > On Thu, Apr 15, 2021 at 5:21 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > >
> > > > Hi Luiz,
> > > >
> > > > Thank you so much. I appreciate it.
> > > >
> > > > That was my bad. I just checked. Our system is Ubuntu 18.04. The
> > > > BlueZ version is "5.48-0ubuntu3.4" which is different from the
> > > > versions in http://www.bluez.org/. I'm trying to figure out if
> > > > this version includes the version 5.50. Do you know the
> > > > corresponding BlueZ version for "5.48-0ubuntu3.4"?
> > >
> > > 5.48, which was the version available in 2018, more than 3 years/10
> > > releases ago, a lot of things have been fixed over this time so Id
> > > really recommend to upgrade to the latest if you want to have some
> > > support.
> > >
> > > > Thanks!
> > > > Kenny
> > > >
> > > > On Thu, Apr 15, 2021 at 1:31 PM Luiz Augusto von Dentz
> > > > <luiz.dentz@gmail.com> wrote:
> > > > >
> > > > > Hi Kenny,
> > > > >
> > > > > On Wed, Apr 14, 2021 at 10:44 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > > > >
> > > > > > Hi Luiz,
> > > > > >
> > > > > > There is a UI example of nRF Connect which shows the "Service
> > > > > > Changed Indication" is under "Generic
> > > > > > Attribute"(http://forum.espruino.com/conversations/357737/).
> > > > > > We're using BlueZ 5.48. I tried to add it by modifying example-gatt-server:
> > > > >
> > > > >
> > > > > You should have mentioned that you are using 5.48, you need the following patch:
> > > > >
> > > > > commit a0b886e26c83ad4dfbf0b2b2e024c8ce9ead9a7d
> > > > > Author: Szymon Janc <szymon.janc@codecoup.pl>
> > > > > Date:   Wed Mar 28 12:10:55 2018 +0200
> > > > >
> > > > >     gatt: Add support for storing Service Changed CCC value
> > > > >
> > > > >     This adds support for storing CCC value of Service Changed
> > > > >     characteristic. Once bluetoothd is restart stored values are read
> > > > >     and any device subscribed to indications will receive Service Changed
> > > > >     indication with 0x00010-0xffff value. This is to invalidate any
> > > > >     non-core services since there is no way to verify if applications
> > > > >     will register their services in same order (or at all).
> > > > >
> > > > >     This fix accessing invalid handles by stacks that rely only on Service
> > > > >     Changed indication for rediscovery ie. Apple iOS.
> > > > >
> > > > > Or upgrade to a BlueZ release that has the above patch, which should be 5.50:
> > > > >
> > > > > +ver 5.50:
> > > > > +       Fix issue with GATT and reading long values.
> > > > > +       Fix issue with GATT and reading multiple includes.
> > > > > +       Fix issue with GATT and service changes when offline.
> > > > > +       Fix issue with handling secondary service discovery.
> > > > > +       Fix issue with handling persistency of CCC values.
> > > > >
> > > > > >
> > > > > > class ServiceChangedChrc(Characteristic):
> > > > > >     SCI_UUID = '00002a05-0000-1000-8000-00805f9b34fb'
> > > > > >
> > > > > >     def __init__(self, bus, index, service):
> > > > > >         Characteristic.__init__(
> > > > > >                 self, bus, index,
> > > > > >                 self.SCI_UUID,
> > > > > >                 ['indicate'],
> > > > > >                 service)
> > > > > >
> > > > > >     def IndicateValue(self, options):
> > > > > >         # This function doesn't exist. Just list it here.
> > > > > >         pass
> > > > > >
> > > > > >
> > > > > > class ServiceChangedService(Service):
> > > > > >     MY_UUID = '00001801-0000-1000-8000-00805f9b34fb'
> > > > > >
> > > > > >     def __init__(self, bus, index):
> > > > > >         Service.__init__(self, bus, index, self.MY_UUID, True)
> > > > > >         self.add_characteristic(ServiceChangedChrc(bus, 0,
> > > > > > self))
> > > > > >
> > > > > >
> > > > > > class Application(dbus.service.Object):
> > > > > >     """
> > > > > >     org.bluez.GattApplication1 interface implementation
> > > > > >     """
> > > > > >     def __init__(self, bus):
> > > > > >         self.path = '/'
> > > > > >         self.services = []
> > > > > >         dbus.service.Object.__init__(self, bus, self.path)
> > > > > >         self.add_service(HeartRateService(bus, 0))
> > > > > >         self.add_service(BatteryService(bus, 1))
> > > > > >         self.add_service(TestService(bus, 2))
> > > > > >         self.add_service(ServiceChangedService(bus, 3))
> > > > > >
> > > > > >
> > > > > > When I run it, there is "Failed to register application:
> > > > > > org.bluez.Error.Failed: Failed to create entry in database".
> > > > > > That is in the function client_ready_cb() in gatt-database.c
> > > > > > in BlueZ code. Do you know how to fix it?
> > > > >
> > > > > You don't need to register Service Changed, the daemon already
> > > > > takes care of registering it and there could only be one Service
> > > > > Changed in the database.
> > > > >
> > > > > > Thanks!
> > > > > > Kenny
> > > > > >
> > > > > > On Tue, Apr 13, 2021 at 9:46 PM Kenny Bian <kennybian@gmail.com> wrote:
> > > > > > >
> > > > > > > Hi Jamie, Luiz,
> > > > > > >
> > > > > > > Thanks for your info.
> > > > > > >
> > > > > > > Luiz, to answer your questions:
> > > > > > > BlueZ doesn't seem to emit "Service Changed Indication". Or
> > > > > > > it does emit it, but we don't know how to verify it.
> > > > > > > Yes, BlueZ acts as a GATT server which runs on Linux.
> > > > > > >
> > > > > > > So my questions:
> > > > > > > How can I tell if "Service Changed Indication" is working? I
> > > > > > > need to show it to our app developers that the GATT server
> > > > > > > does send the "Service Changed Indication" when there is a service change.
> > > > > > > By disabling the GATT's cache in "/etc/bluetooth/main.conf",
> > > > > > > the "Service Changed Indication" is disabled?
> > > > > > > Can "Service Changed Indication" be enabled in a conf file?
> > > > > > > Or should it be done in the Python code? Could you please
> > > > > > > help find out that info?
> > > > > > > Our GATT server is based on the Python code
> > > > > > > examples(https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/test).
> > > > > > > I don't know how to enable "Service Changed Indication" or
> > > > > > > "Robust Caching" in Python code on the GATT server side.
> > > > > > > There is no document or code samples about that. Please let
> > > > > > > me know if there is any document or Python code example.
> > > > > > >
> > > > > > > Thanks!
> > > > > > > Kenny
> > > > > > >
> > > > > > > On Tue, Apr 13, 2021 at 2:57 PM Luiz Augusto von Dentz
> > > > > > > <luiz.dentz@gmail.com> wrote:
> > > > > > > >
> > > > > > > > Hi Jamie, Brian,
> > > > > > > >
> > > > > > > > On Tue, Apr 13, 2021 at 2:03 AM Jamie Mccrae
> > > > > > > > <Jamie.Mccrae@lairdconnect.com> wrote:
> > > > > > > > >
> > > > > > > > > Hi Kenny,
> > > > > > > > > Why not just add the service changed indication as you refer to below? It was purposely designed for this specific purpose, you're trying to work around an issue created because you don't want to use the feature that prevents this issue. Any workaround is just that, a workaround, and might not work as intended.
> > > > > > > >
> > > > > > > > Yep, and while at it implement the so called Robust
> > > > > > > > Caching feature so we can detect if anything has changed by reading the DB Hash.
> > > > > > > >
> > > > > > > > > Thanks,
> > > > > > > > > Jamie
> > > > > > > > >
> > > > > > > > > -----Original Message-----
> > > > > > > > > From: Kenny Bian <kennybian@gmail.com>
> > > > > > > > > Sent: 13 April 2021 06:59
> > > > > > > > > To: linux-bluetooth@vger.kernel.org
> > > > > > > > > Subject: Disabled bluetooth cache. But the app still getting wrong data?
> > > > > > > > >
> > > > > > > > > EXTERNAL EMAIL: Be careful with attachments and links.
> > > > > > > > >
> > > > > > > > > Previously we had an issue: if there is a change of characteristics in the new build of our firmware, then the app will get the wrong data.
> > > > > > > > > By saying changed characteristics, it can be an added or removed characteristic, or adding notification to an existing characteristic.
> > > > > > > > > In order to keep the pairing information, the "/var/lib/bluetooth"
> > > > > > > > > folder is copied over to the new build's partition. We
> > > > > > > > > realized that there is no "service changed indication".
> > > > > > > > > The app can't handle the changed services. So we
> > > > > > > > > disabled the bluetooth cache by set this in
> > > > > > > > > "/etc/bluetooth/main.conf":
> > > > > > > > > [GATT]
> > > > > > > > > Cache = no
> > > > > > > >
> > > > > > > > When you say the app can't handle changed service do you
> > > > > > > > mean BlueZ doesn't emit changes to the attributes (via
> > > > > > > > Service Changed) or is it really the application not being able to handle the changes?
> > > > > > > >
> > > > > > > > > But recently, we saw the problem again even if the
> > > > > > > > > bluetooth cache is
> > > > > > > > > disabled: in the build number 101, a characteristic is removed. But when we upgrade the build from 100 to 101, the app gets the wrong data. We looked at the log. When the app tries to read temperature by using the temperature UUID, somehow the bluetooth service we created received the request to read the "device name"(device name UUID). So the "device name" is returned to the app as the temperature. This looks like the same behavior as the bluetooth cache is not disabled. I looked at the "/var/lib/bluetooth/[BT_MAC]/cache" folder. There is no "[Attributes]" section in the files in the folder. That means the disabled cache seems working.
> > > > > > > >
> > > > > > > > So BlueZ is acting as the server, right? The Cache only
> > > > > > > > applies to the client portion, there is no such thing as disabling the remote cache.
> > > > > > > > I don't see any incoming Read By Group Request from the
> > > > > > > > remote so it is very likely that it has cached the values,
> > > > > > > > there is no Read By Type for the DB Hash either which is
> > > > > > > > quite surprising to me since that is required for stacks
> > > > > > > > supporting Robust Caching which I believe is the case of iOS.
> > > > > > > >
> > > > > > > > Anyway, I would check that the following lines are being triggered:
> > > > > > > >
> > > > > > > > When starting:
> > > > > > > >
> > > > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/sr
> > > > > > > > c/gatt-database.c#n3798
> > > > > > > >
> > > > > > > > On connect:
> > > > > > > >
> > > > > > > > https://git.kernel.org/pub/scm/bluetooth/bluez.git/tree/sr
> > > > > > > > c/gatt-database.c#n3741
> > > > > > > >
> > > > > > > > If those lines are not being triggered it is likely a
> > > > > > > > client problem which for some reason had not subscribed to
> > > > > > > > received service changes for some reason, if it doesn't
> > > > > > > > subscribe to service changes then it shall not cache any
> > > > > > > > attribute and attempt to rediscover on every connection.
> > > > > > > >
> > > > > > > > > The only way to fix this issue is to force exit the mobile app on the phone and "Forget This Device" in iOS or "Unpair" in Android.
> > > > > > > > >
> > > > > > > > > I looked at the btmon(see attached). For the working btmon log, there is "Attribute group list: XX entries" under "ACL Data TX". But there is no "Attribute group list: XX entries" under "ACL Data TX" in the attached problematic btmon log.
> > > > > > > > >
> > > > > > > > > Questions:
> > > > > > > > > 1. How is it possible that this still happens even if the bluetooth cache is disabled?
> > > > > > > > > 2. Is this the problem on the Linux side which runs the GATT server or on the mobile side?
> > > > > > > > > 3. Is there anything else we should look into?
> > > > > > > > >
> > > > > > > > > We're going to release our product soon. This is a critical issue for us. Please help if you have any suggestions.
> > > > > > > > >
> > > > > > > > > Thanks!
> > > > > > > > > THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.
> > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > > > --
> > > > > > > > Luiz Augusto von Dentz
> > > > >
> > > > >
> > > > >
> > > > > --
> > > > > Luiz Augusto von Dentz
> > >
> > >
> > >
> > > --
> > > Luiz Augusto von Dentz

^ permalink raw reply	[flat|nested] 13+ messages in thread

end of thread, other threads:[~2021-04-20 21:35 UTC | newest]

Thread overview: 13+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-04-13  5:59 Disabled bluetooth cache. But the app still getting wrong data? Kenny Bian
2021-04-13  6:39 ` Jamie Mccrae
2021-04-13 17:17   ` Kenny Bian
2021-04-13 21:57   ` Luiz Augusto von Dentz
2021-04-14  4:46     ` Kenny Bian
2021-04-15  5:44       ` Kenny Bian
2021-04-15 20:31         ` Luiz Augusto von Dentz
2021-04-16  0:20           ` Kenny Bian
2021-04-16  0:49             ` Luiz Augusto von Dentz
2021-04-16  3:06               ` Kenny Bian
2021-04-16  4:03                 ` Kenny Bian
2021-04-16  6:34                   ` Jamie Mccrae
2021-04-20 21:35                     ` Kenny Bian

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.