Hi Gilles,
On Mon, Dec 05, 2016 at 02:57:40PM -0800, Gilles Boccon-Gibod wrote:
I am running a simple BLE app on an nRF52 DK board.
In it simplest mode, the app advertises a GATT server with a
WriteNoResponse characteristic.
When I write to this characteristic from a GATT client (a mac in my
case),
my access callback is properly invoked, and I can get the
characteristic
value when this value is "normal" (i.e no more than MTU-3 bytes).
For testing, I set the MTU to 23 with:
ble_att_set_preferred_mtu(23);
I can verify that writing a 20 byte value works fine, as I get a
callback
with ctxt->op == BLE_GATT_ACCESS_OP_WRITE_CHR
However, if I write a value that's 21 bytes or more, the callback is
never
invoked.
At the GATT level, writing a long attribute involves different GATT
commands, namely BLE_ATT_OP_PREP_WRITE_REQ and
BLE_ATT_OP_EXEC_WRITE_REQ,
instead of the one-shot BLE_ATT_OP_WRITE_REQ.
If I enable DEBUG logging, I can see that the
BLE_ATT_OP_EXEC_WRITE_REQ
is
received and processed, but there's no callback to my code.
Unfortunately, I can't seem to replicate that behavior. Which
version
of Mynewt are you using? I tested this with the develop branch. The
latest official release (0.9.0) is quite old, so I am a little less
confident about that one :).
To test this, I used the bletiny sample app with the following
modifictions:
* Increase size of the "Security test, static value"
characteristic
to 40 bytes (was: 1 byte).
* Change this characteristics flags to:
BLE_GATT_CHR_F_READ | BLE_GATT_CHR_F_WRITE_NO_RSP
(was:
BLE_GATT_CHR_F_READ | BLE_GATT_CHR_F_WRITE |
BLE_GATT_CHR_F_WRITE_ENC)
Here is the procedure I used:
* Set preferred MTU on both devices to 23.
* Peripheral begins advertising.
* Central connects.
* Central initiates MTU negotiation.
* Central performs a 40-byte long write
Here is the GDB backtrace on the peripheral showing the callback
getting
executed:
#0 gatt_svr_chr_access_sec_test (conn_handle=1, attr_handle=33,
ctxt=0x20000f80 <bletiny_stack+1828>, arg=0x0) at gatt_svr.c:218
#1 0x000144b6 in ble_gatts_val_access (conn_handle=<optimized out>,
attr_handle=<optimized out>, offset=<optimized out>,
gatt_ctxt=0x20000f80 <bletiny_stack+1828>, om=0x20000fe0
<bletiny_stack+1924>, access_cb=0xad35
<gatt_svr_chr_access_sec_test>,
cb_arg=0x0)
at ble_gatts.c:348
#2 0x000144fc in ble_gatts_chr_val_access (conn_handle=<optimized
out>,
attr_handle=<optimized out>, att_op=<optimized out>,
offset=<optimized out>,
om=0x20000fe0 <bletiny_stack+1924>, arg=0x200004bc
<__compound_literal.7+24>) at ble_gatts.c:374
#3 0x0000f41c in ble_att_svr_write (conn_handle=conn_handle@entry=1,
entry=<optimized out>, om=om@entry=0x20000fe0 <bletiny_stack+1924>,
out_att_err=out_att_err@entry=0x20000fdb <bletiny_stack+1919> "",
offset=0) at ble_att_svr.c:527
#4 0x000107de in ble_att_svr_prep_write (err_handle=<synthetic
pointer>,
prep_list=0x20000fdc <bletiny_stack+1920>, conn_handle=1)
at ble_att_svr.c:2371
#5 ble_att_svr_rx_exec_write (conn_handle=<optimized out>,
rxom=<optimized out>) at ble_att_svr.c:2608
#6 0x0000da88 in ble_att_rx (conn_handle=<optimized out>,
om=0x2000102c
<bletiny_stack+2000>) at ble_att.c:461
#7 0x00016dfc in ble_hs_hci_evt_acl_process (om=0x0) at
ble_hs_hci_evt.c:664
#8 0x0001524e in ble_hs_process_rx_data_queue () at ble_hs.c:199
#9 0x0000bcbe in os_eventq_run (evq=evq@entry=0x200035b8
<bletiny_evq>)
at os_eventq.c:147
#10 0x000081ec in bletiny_task_handler (arg=<optimized out>) at
main.c:1556
#11 0x00000000 in ?? ()
Here is the bletiny log on the peripheral (there was some contention
for
the console buffer in the middle so part of it looks garbled):
b set mtu=23
b set addr=0a:45:00:11:22:33
b set adv_data uuid16=0x1811 name=micosa-1 name_is_complete=1 flags=0
tx_pwr_lvl=-128
b adv c10467:[ts=on81773388ssb, mod=n4 lev=und dic=geen
l=0] ble_hs_hci_cmd_send: ogf=0x08 ocf=0x07 len=0
10470:[ts=81796824ssb, mod=4 level=0] 0x07 0x20 0x00
10471:[ts=81804636ssb, mod=4 level=0] Command complete: cmd_pkts=1
ogf=0x8
ocf=0x7 status=0
10474:[ts=81828072ssb, mod=4 level=1] GAP procedure initiated:
advertise;
disc_mode=0 peer_addr_type=0 peer_addr=00:00:00:00:00:00
adv_channel_map=0
own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
adv_data_len=17
10480:[ts=81874944ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
ocf=0x06 len=15
10483:[ts=81898380ssb, mod=4 level=0] 0x06 0x20 0x0f 0x30 0x00 0x60
0x00
0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x07 0x00
10486:[ts=81921816ssb, mod=4 level=0] Command complete: cmd_pkts=1
ogf=0x8
ocf=0x6 status=0
10488:[ts=81937440ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
ocf=0x08 len=32
10490:[ts=81953064ssb, mod=4 level=0] 0x08 0x20 0x20 0x14 0x03 0x02
0x11
0x18 0x09 0x08 0x6d 0x69 0x63 0x6f 0x73 0x61 0x2d 0x31 0x02 0x0a 0x00
0x02
0x01 0x06 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
10496:[ts=82000000ssb, mod=4 level=0] Command complete: cmd_pkts=1
ogf=0x8
ocf=0x8 status=0
10498:[ts=82015624ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
ocf=0x09 len=32
10501:[ts=82039060ssb, mod=4 level=0] 0x09 0x20 0x20 0x00 0x00 0x00
0x00
0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
0x00
0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
10507:[ts=82085932ssb, mod=4 level=0] Command complete: cmd_pkts=1
ogf=0x8
ocf=0x9 status=0
10509:[ts=82101556ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
ocf=0x0a len=1
10511:[ts=82117180ssb, mod=4 level=0] 0x0a 0x20 0x01 0x01
10513:[ts=82132804ssb, mod=4 level=0] Command complete: cmd_pkts=1
ogf=0x8
ocf=0xa status=0
11245:[ts=87851508ssb, mod=4 level=0] LE connection complete.
handle=1
role=1 paddrtype=0 addr=a.b.c.d.e.f local_rpa=0.0.0.0.0.0
peer_rpa=0.0.0.0.0.0 itvl=40 latency=0 spvn_tmo=256 mca=4
11250:connection established; status=0 handle=1 our_ota_addr_type=0
our_ota_addr=0a:45:00:11:22:33 our_id_addr_type=0
our_id_addr=0a:45:00:11:22:33 peer_ota_addr_type=0
peer_ota_addr=0a:0b:0c:0d:0e:0f peer_id_addr_type=0
peer_id_addr=0a:0b:0c:0d:0e:0f conn_itvl=40 conn_latency=0
supervision_timeout=256 encrypted=0 authenticated=0 bonded=0
11258:[ts=87953064ssb, mod=4 level=0] Number of Completed Packets:
num_handles=1
11261:[ts=87976500ssb, mod=4 level=0] handle:1 pkts:0
12442:[ts=97203112ssb, mod=4 level=0] ble_hs_hci_evt_acl_process():
conn_handle=1 pb=2 len=7 data=0x03 0x00 0x04 0x00 0x02 0x17 0x00
12445:[ts=97226548ssb, mod=4 level=0] rxed att command: mtu req;
conn=1
mtu=23
12447:[ts=97242172ssb, mod=4 level=0] txed att command: mtu rsp;
conn=1
mtu=23
12449:[ts=97257796ssb, mod=4 level=0] host tx hci data; handle=1
length=7
12451:[ts=97273420ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00
0x07
0x00 0x03 0x00 0x04 0x00 0x03 0x17 0x00
12454:mtu update event; conn_handle=1 cid=4 mtu=23
12461:[ts=97351540ssb, mod=4 level=0] Number of Completed Packets:
num_handles=1
12463:[ts=97367164ssb, mod=4 level=0] handle:1 pkts:1
15853:[ts=123851508ssb, mod=4 level=0] ble_hs_hci_evt_acl_process():
conn_handle=1 pb=2 len=27 data=0x17 0x00 0x04 0x00 0x16 0x21 0x00
0x00 0x00
0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02
0x02
0x02 0x02 0x02
15860:[ts=123906192ssb, mod=4 level=0] rxed att command: prep write
req;
conn=1 handle=0x0021 offset=0
15862:[ts=123921816ssb, mod=4 level=0] txed att command: prep write
rsp;
conn=1 handle=0x0021 offset=0
15865:[ts=123945252ssb, mod=4 level=0] host tx hci data; handle=1
length=27
15867:[ts=123960876ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00
0x1b
0x00 0x17 0x00 0x04 0x00 0x17 0x21 0x00 0x00 0x00 0x02 0x02 0x02 0x02
0x02
0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02
15885:[ts=124101556ssb, mod=4 level=0] Number of Completed Packets:
num_handles=1
15887:[ts=124117180ssb, mod=4 level=0] handle:1 pkts:1
15898:[ts=124203112ssb, mod=4 level=0] ble_hs_hci_evt_acl_process():
conn_handle=1 pb=2 len=27 data=0x17 0x00 0x04 0x00 0x16 0x21 0x00
0x12 0x00
0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02
0x02
0x02 0x02 0x02
15904:[ts=124249984ssb, mod=4 level=0] rxed att command: prep write
req;
conn=1 handle=0x0021 offset=18
15907:[ts=124273420ssb, mod=4 level=0] txed att command: prep write
rsp;
conn=1 handle=0x0021 offset=18
15909:[ts=124289044ssb, mod=4 level=0] host tx hci data; handle=1
length=27
15912:[ts=124312480ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00
0x1b
0x00 0x17 0x00 0x04 0x00 0x17 0x21 0x00 0x12 0x00 0x02 0x02 0x02 0x02
0x02
0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02 0x02
15924:[ts=124406224ssb, mod=4 level=0] Number of Completed Packets:
num_handles=1
15926:[ts=124421848ssb, mod=4 level=0] handle:1 pkts:1
15936:[ts=124499968ssb, mod=4 level=0] ble_hs_hci_evt_acl_process():
conn_handle=1 pb=2 len=13 data=0x09 0x00 0x04 0x00 0x16 0x21 0x00
0x24 0x00
0x02 0x02 0x02 0x02
15941:[ts=124539028ssb, mod=4 level=0] rxed att command: prep write
req;
conn=1 handle=0x0021 offset=36
15944:[ts=124562464ssb, mod=4 level=0] txed att command: prep write
rsp;
conn=1 handle=0x0021 offset=36
15946:[ts=124578088ssb, mod=4 level=0] host tx hci data; handle=1
length=13
15949:[ts=124601524ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00
0x0d
0x00 0x09 0x00 0x04 0x00 0x17 0x21 0x00 0x24 0x00 0x02 0x02 0x02 0x02
15962:[ts=124703080ssb, mod=4 level=0] Number of Completed Packets:
num_handles=1
15964:[ts=124718704ssb, mod=4 level=0] handle:1 pkts:1
15975:[ts=124804636ssb, mod=4 level=0] ble_hs_hci_evt_acl_process():
conn_handle=1 pb=2 len=6 data=0x02 0x00 0x04 0x00 0x18 0x01
15978:[ts=124828072ssb, mod=4 level=0] rxed att command: exec write
req;
conn=1 flags=0x01
19688:[ts=153812448ssb, mod=4 level=0] host tx hci data; handle=1
length=5
19691:[ts=153835884ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00
0x05
0x00 0x01 0x00 0x04 0x00 0x19
Thanks,
Chris
