Hi Luiz,
Correct, the request is timing out. The problem is "prep_write_complete_cb" is never getting called after the "prep_write_cb" is called. The prep_write_complete_cb is responsible for sending the response BT_ATT_OP_PREP_WRITE_RSP back. The patch I provided fixes the code so that prep_write_complete_cb will get called and the response is sent back. Sorry, I had debugged this issue a quite a while ago using bluez 5.55 and 5.66 and noticed the same issue in the master branch. We have been using the patch and it has resolved the issue.
Thanks,
Trey
-----Original Message-----
From: Luiz Augusto von Dentz <luiz.dentz@xxxxxxxxx>
Sent: Wednesday, July 10, 2024 4:14 PM
To: Ramsay, Trey <Trey_Ramsay@xxxxxxxx>
Cc: linux-bluetooth@xxxxxxxxxxxxxxx
Subject: Re: [PATCH] ATT: Error (0x01) - Error: Unlikely error (14) Prepare Write req (0x16)
[EXTERNAL EMAIL]
Hi Trey,
On Wed, Jul 10, 2024 at 3:55 PM Ramsay, Trey <Trey.Ramsay@xxxxxxxx> wrote:
>
> Hi Luis,
> It is a Prepare Write Request but prep_write_complete_cb is never getting called. In gatt_db_attribute_write, the prep_write_complete_cb function is not getting called since "attribe->write_func" is not null and the function will return "True". The prep_write_complete_cb is supposed to get called after "goto done;" but it's not getting called. The prep_write_complete_cb is assigned to "func". The patch checks to see if len is 0 and will goto done which will call prep_write_complete_cb.
Well if it returns true then it should not return unlikely:
status = gatt_db_attribute_write(attr, offset, NULL, 0,
BT_ATT_OP_PREP_WRITE_REQ,
server->att,
prep_write_complete_cb, pwcd);
if (status)
return;
ecode = BT_ATT_ERROR_UNLIKELY;
error:
bt_att_chan_send_error_rsp(chan, opcode, handle, ecode);
>
> > ACL data: handle 0 flags 0x01 dlen 3
> ATT: Prepare Write req (0x16)
> attr handle 0x0069, value offset 0x0000
> part attr value 0x80 0x02 0x00 0x01 0xaa 0xd3 0x81 0x51 0x54
> 0x5b 0xea 0xaf 0x68 0x0d 0xeb 0xe6 0x11 0x2d 0x63 0xb1 0x8e 0xbd 0xc4
> 0x63 0x8f 0xf6 0xb6 0x10 0x63 0xb5 0x54 0x3f 0x36 0x19 0x41 0x5b 0x25
> 0xcd 0xa7 0xe5 0x9d 0xc7 0x71 0x26 0x33 0x7c 0xe8 0x0e 0x67 0xd8 0x9a
> 0x0a 0xb5 0xe5 0x24 0x87 0x2d 0xcc 0x00 0xa9 0xc8 0xb8 0x95 0x76 0x75
> 0x9f 0x79 0x1f 0x94 0xe4 0xd9 0xbe 0xab 0x22 0xa3 0x33 0x18 0x28 0x57
> 0x26 0xae 0x6d 0x0a 0x9b 0x63 0xeb 0x10 0xf3 0xb5 0xea 0x64 0x4a 0x81
> 0x55 0xe0 0xa9 0x43 0x8c 0x87 0xb4 0x32 0x1c 0x79 0xd6 0x34 0x97 0xff
> 0xae 0x71 0x1e 0x50 0x7c 0xb6 0x72 0x7b 0x49 0x44 0xef 0xfe 0xe2 0x40
> 0xc7 0x3e 0x5e 0x42 0x9b 0xca 0xa4 0x61 0x66 0x72 0x0a 0x1d 0x5c 0xb0
> 0xdb 0xa1 0xbb 0xf7 0xb6 0x27 0xa0 0x67 0xde 0x69 0xd9 0x67 0xa7 0x09
> 0x58 0x71 0x37 0x99 0x95 0x5c 0x5d 0x10 0x4d 0xed 0x2f 0xe2 0x85 0x6c
> 0x03 0x60 0x80 0x67 0x25 0x1b 0x33 0x02 0x53 0xbe 0x67 0xdb 0xd4 0x2a
> 0x9e 0x8d 0x82 0xe2 0x9d 0xc4 0x86 0x08 0x84 0x2c 0xbf 0xa5 0xc5 0xd3
> 0x99 0xf1 0x02 0x09 0x80 0x0c 0xc5 0xf9 0x99 0x06 0x20 0x01 0x75 0xdb
> 0x0c 0x11 0x81 0x87 0x04 0x4d 0xf0 0xcc 0xf7 0x27 0x85 0xcd 0x22 0x84
> 0x85 0x04 0xb3 0xa2 0xa9 0xcc 0xe9 0x27 0x8b 0x67 0x02 0x1b 0xe0 0x8c
> 0xd7 0x8f 0x51 0x3a 0xa6 0x0c 0x23 0xa0 0x09 0x2b 0x4c 0xb0 0x80 0x34
> 0xf9 0x61 0xaa 0x72 0x90 0x3a 0x5e 0xb7 0x11 0xaf 0xc3 0xcd 0x78 0x4f
> 0xb6 0x1b 0xbb 0xb4 0xb2 0x42 0x9f 0x87 0xad 0xf6 0xa1 0xae 0xdd 0xde
> 0x38 0x09 0x7a 0xc5 0x7c 0xbd 0x98 0x89 0xae 0x49 0x98 0xe7 0xae 0x92
> 0x28 0x45 0x5a 0xbc 0x30 0x53 0xe5 0xc1 0x56 0xb3 0x9f 0x56 0x7b 0xa1
> 0x02 0xcd 0xc2 0x25 0x2a 0xb2 0xc5 0xc9 0x35 0xec 0xa7 0x26 0x79 0x97
> 0x2e 0x96 0x97 0x3e 0x5b 0x8f 0xc7 0x2f 0xa8 0x39 0x70 0xb1 0x22 0x5b
> 0x2c 0x15 0x41 0xec 0x6b 0xc4 0x1e 0x2d 0xc0 0x47 0x75 0x42 0x01 0x40
> 0xc5 0x17 0x69 0xf4 0x0a 0xcd 0x7e 0x62 0x25 0xec 0x1f 0x7c 0xae 0x7b
> 0xf9 0x1e 0x9f 0x98 0xbd 0xc7 0xc3 0x44 0x4c 0xe2 0x0a 0x8c 0xbe 0xeb
> 0x1e 0xae 0x7b 0xbc 0x49 0xfa 0x7d 0xa3 0xdf 0xb2 0xc0 0x69 0xf7 0x57
> 0x6b 0x6f 0xe7 0x2e 0x3c 0x90 0x0a 0x16 0xe8 0x03 0x0d 0xf1 0x9c 0x4c
> 0xa3 0x4b 0xcf 0x6d 0xc3 0x4a 0x69 0x25 0xc5 0xf6 0x9c 0x4b 0xb3 0x77
> 0x67 0x7b 0x00 0xbb 0x1f 0xcd 0x59 0xb0 0xe9 0xf6 0xbe 0xa3 0x41 0xd1
> 0x2c 0x1f 0x09 0x6b 0x4e 0x52 0x01 0x0c 0xe1 0x20 0x6c 0x76 0xfd 0xc9
> 0xb9 0xb4 0xd8 0xdf 0xcb 0xac 0x77 0x65 0xcd 0x98 0xe9 0x66 0x6c 0xc8
> 0x8f 0xfc 0xef 0x7e 0x48 0x9f 0xc8 0xd6 0x9c 0x72 0xac 0x44 0xa3 0x67
> 0xa3 0x6a 0xe3 0xde 0x3a 0xd5 0x21 0x94 0x29 0x94 0x3d 0x7b 0x88 0x29
> 0xc3 0xc2 0x7e 0x82 0x9d 0xe7 0x00 0x7c 0x96 0x28 0x1d 0x20 0xf8 0x81
> 0x02 0x7c 0xc2 0xb2 0xfa 0x43 0x90 0x6e
That doesn't seem like a zero length, what BlueZ version is this btw?
> < ACL data: handle 0 flags 0x00 dlen 9
> ATT: Error (0x01)
> Error: Unlikely error (14)
> Prepare Write req (0x16) on handle 0x0069
Check what time does this error is generated, since this well be:
static bool write_timeout(void *user_data) {
struct pending_write *p = user_data;
p->timeout_id = 0;
queue_remove(p->attrib->pending_writes, p);
pending_write_result(p, -ETIMEDOUT);
return false;
}
The -ETIMEOUT would be converted to:
static uint8_t att_ecode_from_error(int err) {
/*
* If the error fits in a single byte, treat it as an ATT protocol
* error as is. Since "0" is not a valid ATT protocol error code, we map
* that to UNLIKELY below.
*/
if (err > 0 && err < UINT8_MAX)
return err;
/*
* Since we allow UNIX errnos, map them to appropriate ATT protocol
* and "Common Profile and Service" error codes.
*/
switch (err) {
case -ENOENT:
return BT_ATT_ERROR_INVALID_HANDLE;
case -ENOMEM:
return BT_ATT_ERROR_INSUFFICIENT_RESOURCES;
case -EALREADY:
return BT_ERROR_ALREADY_IN_PROGRESS;
case -EOVERFLOW:
return BT_ERROR_OUT_OF_RANGE;
}
return BT_ATT_ERROR_UNLIKELY;
}
So on write_timeout it would also generate the unlikely error.
Note that normally prepare write don't need authorization, but perhaps you have an application setting 'authorize':
https://urldefense.com/v3/__https://github.com/bluez/bluez/blob/master/doc/org.bluez.GattCharacteristic.rst*arraystring-flags-read-only__;Iw!!LpKI!mOAXmul0EbN_7I2R6edizAu4TW4H0BMt5s6EDMhpj23Ap8xFtV5BRjMJtpqVFcVIZQnbtBdGNs0UyAwX178$ [github[.]com], which means the following code would execute:
if (opcode == BT_ATT_OP_PREP_WRITE_REQ) {
if (!btd_device_is_trusted(device) && !desc->prep_authorized &&
desc->req_prep_authorization)
send_write(att, attrib, desc->proxy,
desc->pending_writes, id, value, len,
offset, false, true);
else
gatt_db_attribute_write_result(attrib, id, 0);
return;
}
You can also try adding passing -t -p debug to btmon so it logs the debug messages from bluetoothd and include timing information.
> > HCI Event: Number of Completed Packets (0x13) plen 5
> handle 0 packets 1
> > ACL data: handle 0 flags 0x02 dlen 6
> ATT: Exec Write req (0x18)
> cancel all prepared writes (0x00) < ACL data: handle 0 flags
> 0x00 dlen 5
> ATT: Exec Write resp (0x19)
> > HCI Event: Number of Completed Packets (0x13) plen 5
> handle 0 packets 1
>
> -----Original Message-----
> From: Luiz Augusto von Dentz <luiz.dentz@xxxxxxxxx>
> Sent: Tuesday, July 9, 2024 3:34 PM
> To: Ramsay, Trey <Trey_Ramsay@xxxxxxxx>
> Cc: linux-bluetooth@xxxxxxxxxxxxxxx
> Subject: Re: [PATCH] ATT: Error (0x01) - Error: Unlikely error (14)
> Prepare Write req (0x16)
>
>
> [EXTERNAL EMAIL]
>
> Hi Trey,
>
> On Tue, Jul 9, 2024 at 1:34 PM Ramsay, Trey <Trey.Ramsay@xxxxxxxx> wrote:
> >
> > Bluez Maintainers,
> > Here is a fix for attribute writes not working in
> > src/shared/gatt-db.c. The prep_write_complete_cb was not getting
> > called. The attrib->write_func code block should not be called when
> > len is 0
> >
> > commit 5a9baa10d4fde7ca8ab88ecd68e17671c33cb587 (HEAD -> gat-db,
> > master)
> > Author: Trey_Ramsay <trey_ramsay@xxxxxxxx>
> > Date: Fri May 31 15:39:27 2024 -0500
> >
> > shared/gatt-db: Prepare Write req error BT_ATT_ERROR_UNLIKELY
> >
> > Fixes Prepare Write req error: BT_ATT_ERROR_UNLIKELY
> >
> > ATT: Error (0x01)
> > Error: Unlikely error (14)
> > Prepare Write req (0x16) on handle 0x0069
> >
> > The prep_write_complete_cb was not getting called
> > The attrib->write_func code block does not need to be called
> > when len is 0
>
> This doesn't sound quite right, 0 length still needs to be passed to the attribute to confirm since we don't know if it could be a procedure or not. Can you explain what attribute is being written and if it could be due to the application not responding and the procedure timing out (e.g. write_timeout is called?), perhaps if you can paste a btmon trace as well that could help checking what attribute it is trying to use prepare write.
>
> > diff --git a/src/shared/gatt-db.c b/src/shared/gatt-db.c index
> > 2c8e7d31e..678aef4cf 100644
> > --- a/src/shared/gatt-db.c
> > +++ b/src/shared/gatt-db.c
> > @@ -2127,6 +2127,10 @@ bool gatt_db_attribute_write(struct gatt_db_attribute *attrib, uint16_t offset,
> > if (!attrib || (!func && attrib->write_func))
> > return false;
> >
> > + /* Nothing to write just skip */
> > + if (len == 0)
> > + goto done;
> > +
> > if (attrib->write_func) {
> > struct pending_write *p;
> >
> > @@ -2162,10 +2166,6 @@ bool gatt_db_attribute_write(struct gatt_db_attribute *attrib, uint16_t offset,
> > return true;
> > }
> >
> > - /* Nothing to write just skip */
> > - if (len == 0)
> > - goto done;
> > -
> > /* For values stored in db allocate on demand */
> > if (!attrib->value || offset >= attrib->value_len ||
> > len > (unsigned) (attrib->value_len - offset)) {
> >
> >
> >
> > -----Original Message-----
> > From: Ramsay, Trey <Trey.Ramsay@xxxxxxxx>
> > Sent: Thursday, June 20, 2024 1:58 PM
> > To: linux-bluetooth@xxxxxxxxxxxxxxx
> > Subject: [PATCH] ATT: Error (0x01) - Error: Unlikely error (14)
> > Prepare Write req (0x16)
> >
> >
> > Bluez Maintainers
> > Here is a fix for attribute writes not working in
> > src/shared/gatt-db.c
> >
> > https://urldefense.com/v3/__https://github.com/tramsay/bluez-tramsay
> > /c
> > ommit/246bc960629dff34e744c728f048e9f50f1a005d__;!!LpKI!jkJYamzU8bOd
> > d1
> > qt-sWpj6gy1YwS30UyamHLUJj9Uy0UecrB6QxvCdSWFAUH7Dvq2wVJqu1C5jjoX5amyw
> > JH
> > $ [github[.]com]
> >
> > shared/gatt-db: Prepare Write req error BT_ATT_ERROR_UNLIKELY Fixes
> > Prepare Write req error: BT_ATT_ERROR_UNLIKELY
> >
> > ATT: Error (0x01)
> > Error: Unlikely error (14)
> > Prepare Write req (0x16) on handle 0x0069
> >
> > The prep_write_complete_cb was not getting called The
> > attrib->write_func code block should not be called when len is 0
> >
>
>
> --
> Luiz Augusto von Dentz
>
--
Luiz Augusto von Dentz
