[RFC BlueZ] adapter: Introduce BTD_ADAPTER_DBG

[RFC BlueZ] adapter: Introduce BTD_ADAPTER_DBG

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This introduces BTD_ADAPTER_DBG which includes the controller index
when using DBG_IDX, in addition to it also add similar macro for
devices in the form of BTD_DEVICE_DBG which resolves the adapter and
before calling BTD_ADAPTER_DBG.
---
 src/adapter.h | 4 ++++
 src/device.h  | 4 ++++
 2 files changed, 8 insertions(+)

diff --git a/src/adapter.h b/src/adapter.h
index 35deb1d11..515be3210 100644
--- a/src/adapter.h
+++ b/src/adapter.h
@@ -23,6 +23,10 @@
 /* Invalid SSP passkey value used to indicate negative replies */
 #define INVALID_PASSKEY		0xffffffff
 
+#define BTD_ADAPTER_DBG(adapter, fmt, arg...) \
+	DBG_IDX(btd_adapter_get_index(adapter), "%s:%s() " fmt, __FILE__, \
+							__func__ , ## arg)
+
 struct btd_adapter;
 struct btd_device;
 struct queue;
diff --git a/src/device.h b/src/device.h
index 071576d6b..4d40d1d22 100644
--- a/src/device.h
+++ b/src/device.h
@@ -11,6 +11,10 @@
 
 #define DEVICE_INTERFACE	"org.bluez.Device1"
 
+#define BTD_DEVICE_DBG(device, fmt, arg...) \
+	BTD_ADAPTER_DBG(device_get_adapter(device), "%s:%s() " fmt, __FILE__, \
+							__func__ , ## arg)
+
 struct btd_device;
 
 struct btd_device *device_create(struct btd_adapter *adapter,
-- 
2.35.1

[PATCH BlueZ v4 1/9] log: Don't log __FILE__ and __func__ with DBG_IDX

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This removes __FILE__ and __func__ from DBG_IDX since users of it may
already contain such information embedded in the format.
---
 src/log.h | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/src/log.h b/src/log.h
index 74941beb2..1ed742a0d 100644
--- a/src/log.h
+++ b/src/log.h
@@ -9,6 +9,7 @@
  */
 
 #include <stdint.h>
+#include <stdbool.h>
 
 void info(const char *format, ...) __attribute__((format(printf, 1, 2)));
 
@@ -52,10 +53,11 @@ void __btd_enable_debug(struct btd_debug_desc *start,
 		.file = __FILE__, .flags = BTD_DEBUG_FLAG_DEFAULT, \
 	}; \
 	if (__btd_debug_desc.flags & BTD_DEBUG_FLAG_PRINT) \
-		btd_debug(idx, "%s:%s() " fmt, __FILE__, __func__ , ## arg); \
+		btd_debug(idx, fmt, ## arg); \
 } while (0)
 
-#define DBG(fmt, arg...) DBG_IDX(0xffff, fmt, ## arg)
+#define DBG(fmt, arg...) \
+	DBG_IDX(0xffff, "%s:%s() " fmt, __FILE__, __func__, ## arg)
 #define error(fmt, arg...) \
 	btd_error(0xffff, "%s:%s() " fmt, __FILE__, __func__, ## arg)
 #define warn(fmt, arg...) \
-- 
2.35.1

RE: [BlueZ,v4,1/9] log: Don't log __FILE__ and __func__ with DBG_IDX

[bluez.test.bot]

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

This is automated email and please do not reply to this email!

Dear submitter,

Thank you for submitting the patches to the linux bluetooth mailing list.
This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=625873

---Test result---

Test Summary:
CheckPatch                    PASS      1.36 seconds
GitLint                       PASS      0.96 seconds
Prep - Setup ELL              PASS      42.81 seconds
Build - Prep                  PASS      0.72 seconds
Build - Configure             PASS      8.56 seconds
Build - Make                  PASS      1291.43 seconds
Make Check                    PASS      11.92 seconds
Make Check w/Valgrind         PASS      440.83 seconds
Make Distcheck                PASS      226.74 seconds
Build w/ext ELL - Configure   PASS      8.66 seconds
Build w/ext ELL - Make        PASS      1251.70 seconds
Incremental Build with patchesPASS      0.00 seconds



---
Regards,
Linux Bluetooth

Re: [BlueZ,v4,1/9] log: Don't log __FILE__ and __func__ with DBG_IDX

[Luiz Augusto von Dentz]

Hi,

On Wed, Mar 23, 2022 at 4:39 PM <bluez.test.bot@gmail.com> wrote:
>
> This is automated email and please do not reply to this email!
>
> Dear submitter,
>
> Thank you for submitting the patches to the linux bluetooth mailing list.
> This is a CI test results with your patch series:
> PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=625873
>
> ---Test result---
>
> Test Summary:
> CheckPatch                    PASS      1.36 seconds
> GitLint                       PASS      0.96 seconds
> Prep - Setup ELL              PASS      42.81 seconds
> Build - Prep                  PASS      0.72 seconds
> Build - Configure             PASS      8.56 seconds
> Build - Make                  PASS      1291.43 seconds
> Make Check                    PASS      11.92 seconds
> Make Check w/Valgrind         PASS      440.83 seconds
> Make Distcheck                PASS      226.74 seconds
> Build w/ext ELL - Configure   PASS      8.66 seconds
> Build w/ext ELL - Make        PASS      1251.70 seconds
> Incremental Build with patchesPASS      0.00 seconds
>
>
>
> ---
> Regards,
> Linux Bluetooth
>

Pushed.

-- 
Luiz Augusto von Dentz

Re: [PATCH BlueZ v4 1/9] log: Don't log __FILE__ and __func__ with DBG_IDX

[patchwork-bot+bluetooth]

Hello:

This patch was applied to bluetooth/bluez.git (master)
by Luiz Augusto von Dentz <luiz.von.dentz@intel.com>:

On Wed, 23 Mar 2022 15:39:55 -0700 you wrote:
> From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
> 
> This removes __FILE__ and __func__ from DBG_IDX since users of it may
> already contain such information embedded in the format.
> ---
>  src/log.h | 6 ++++--
>  1 file changed, 4 insertions(+), 2 deletions(-)

Here is the summary with links:
  - [BlueZ,v4,1/9] log: Don't log __FILE__ and __func__ with DBG_IDX
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=a3c9409035de

You are awesome, thank you!
-- 
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html

Re: [PATCH BlueZ v4 1/9] log: Don't log __FILE__ and __func__ with DBG_IDX

[Marcel Holtmann]

Hi Luiz,

> This removes __FILE__ and __func__ from DBG_IDX since users of it may
> already contain such information embedded in the format.
> ---
> src/log.h | 6 ++++--
> 1 file changed, 4 insertions(+), 2 deletions(-)
> 
> diff --git a/src/log.h b/src/log.h
> index 74941beb2..1ed742a0d 100644
> --- a/src/log.h
> +++ b/src/log.h
> @@ -9,6 +9,7 @@
>  */
> 
> #include <stdint.h>
> +#include <stdbool.h>

seems to have nothing to do with the change here.

> void info(const char *format, ...) __attribute__((format(printf, 1, 2)));
> 
> @@ -52,10 +53,11 @@ void __btd_enable_debug(struct btd_debug_desc *start,
> 		.file = __FILE__, .flags = BTD_DEBUG_FLAG_DEFAULT, \
> 	}; \
> 	if (__btd_debug_desc.flags & BTD_DEBUG_FLAG_PRINT) \
> -		btd_debug(idx, "%s:%s() " fmt, __FILE__, __func__ , ## arg); \
> +		btd_debug(idx, fmt, ## arg); \
> } while (0)
> 
> -#define DBG(fmt, arg...) DBG_IDX(0xffff, fmt, ## arg)
> +#define DBG(fmt, arg...) \
> +	DBG_IDX(0xffff, "%s:%s() " fmt, __FILE__, __func__, ## arg)
> #define error(fmt, arg...) \
> 	btd_error(0xffff, "%s:%s() " fmt, __FILE__, __func__, ## arg)
> #define warn(fmt, arg...) \

I am still failing to see why this is better.

Regards

Marcel

[PATCH BlueZ v4 2/9] mgmt: Add DBG macro

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This adds mgmt_log wrapper for util_debug and DBG so file and function
names are printed with the logs.
---
 src/shared/mgmt.c | 36 ++++++++++++++++++++++--------------
 1 file changed, 22 insertions(+), 14 deletions(-)

diff --git a/src/shared/mgmt.c b/src/shared/mgmt.c
index 95229c248..c7e6a6c1d 100644
--- a/src/shared/mgmt.c
+++ b/src/shared/mgmt.c
@@ -27,6 +27,9 @@
 #include "src/shared/mgmt.h"
 #include "src/shared/timeout.h"
 
+#define DBG(_mgmt, _format, arg...) \
+	mgmt_log(_mgmt, "%s:%s() " _format, __FILE__, __func__, ## arg)
+
 struct mgmt {
 	int ref_count;
 	int fd;
@@ -177,6 +180,18 @@ static bool request_timeout(void *data)
 	return false;
 }
 
+static void mgmt_log(struct mgmt *mgmt, const char *format, ...)
+{
+	va_list ap;
+
+	if (!mgmt || !format || !mgmt->debug_callback)
+		return;
+
+	va_start(ap, format);
+	util_debug_va(mgmt->debug_callback, mgmt->debug_data, format, ap);
+	va_end(ap);
+}
+
 static bool send_request(struct mgmt *mgmt, struct mgmt_request *request)
 {
 	struct iovec iov;
@@ -187,8 +202,8 @@ static bool send_request(struct mgmt *mgmt, struct mgmt_request *request)
 
 	ret = io_send(mgmt->io, &iov, 1);
 	if (ret < 0) {
-		util_debug(mgmt->debug_callback, mgmt->debug_data,
-				"write failed: %s", strerror(-ret));
+		DBG(mgmt, "write failed: %s", strerror(-ret));
+
 		if (request->callback)
 			request->callback(MGMT_STATUS_FAILED, 0, NULL,
 							request->user_data);
@@ -202,9 +217,7 @@ static bool send_request(struct mgmt *mgmt, struct mgmt_request *request)
 							request,
 							NULL);
 
-	util_debug(mgmt->debug_callback, mgmt->debug_data,
-				"[0x%04x] command 0x%04x",
-				request->index, request->opcode);
+	DBG(mgmt, "[0x%04x] command 0x%04x", request->index, request->opcode);
 
 	util_hexdump('<', request->buf, ret, mgmt->debug_callback,
 							mgmt->debug_data);
@@ -283,9 +296,7 @@ static void request_complete(struct mgmt *mgmt, uint8_t status,
 	request = queue_remove_if(mgmt->pending_list,
 					match_request_opcode_index, &match);
 	if (!request) {
-		util_debug(mgmt->debug_callback, mgmt->debug_data,
-				"Unable to find request for opcode 0x%04x",
-				opcode);
+		DBG(mgmt, "Unable to find request for opcode 0x%04x", opcode);
 
 		/* Attempt to remove with no opcode */
 		request = queue_remove_if(mgmt->pending_list,
@@ -383,8 +394,7 @@ static bool can_read_data(struct io *io, void *user_data)
 		cc = mgmt->buf + MGMT_HDR_SIZE;
 		opcode = btohs(cc->opcode);
 
-		util_debug(mgmt->debug_callback, mgmt->debug_data,
-				"[0x%04x] command 0x%04x complete: 0x%02x",
+		DBG(mgmt, "[0x%04x] command 0x%04x complete: 0x%02x",
 						index, opcode, cc->status);
 
 		request_complete(mgmt, cc->status, opcode, index, length - 3,
@@ -394,15 +404,13 @@ static bool can_read_data(struct io *io, void *user_data)
 		cs = mgmt->buf + MGMT_HDR_SIZE;
 		opcode = btohs(cs->opcode);
 
-		util_debug(mgmt->debug_callback, mgmt->debug_data,
-				"[0x%04x] command 0x%02x status: 0x%02x",
+		DBG(mgmt, "[0x%04x] command 0x%02x status: 0x%02x",
 						index, opcode, cs->status);
 
 		request_complete(mgmt, cs->status, opcode, index, 0, NULL);
 		break;
 	default:
-		util_debug(mgmt->debug_callback, mgmt->debug_data,
-				"[0x%04x] event 0x%04x", index, event);
+		DBG(mgmt, "[0x%04x] event 0x%04x", index, event);
 
 		process_notify(mgmt, event, index, length,
 						mgmt->buf + MGMT_HDR_SIZE);
-- 
2.35.1

[PATCH BlueZ v4 3/9] mgmt: Introduce mgmt_set_verbose

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This introduces mgmt_set_verbose which can be used to enable printing
the the likes hexdump of packets, by default it is disabled since in
most cases the hexdump is not very useful and there are better tools
to collect the hexdumo like btmon.
---
 src/shared/mgmt.c | 24 ++++++++++++++++++++----
 src/shared/mgmt.h |  1 +
 2 files changed, 21 insertions(+), 4 deletions(-)

diff --git a/src/shared/mgmt.c b/src/shared/mgmt.c
index c7e6a6c1d..cf518cc2b 100644
--- a/src/shared/mgmt.c
+++ b/src/shared/mgmt.c
@@ -50,6 +50,7 @@ struct mgmt {
 	mgmt_debug_func_t debug_callback;
 	mgmt_destroy_func_t debug_destroy;
 	void *debug_data;
+	bool verbose;
 };
 
 struct mgmt_request {
@@ -192,6 +193,15 @@ static void mgmt_log(struct mgmt *mgmt, const char *format, ...)
 	va_end(ap);
 }
 
+static void mgmt_hexdump(struct mgmt *mgmt, char dir, const void *data,
+							size_t len)
+{
+	if (!mgmt->verbose)
+		return;
+
+	util_hexdump(dir, data, len, mgmt->debug_callback, mgmt->debug_data);
+}
+
 static bool send_request(struct mgmt *mgmt, struct mgmt_request *request)
 {
 	struct iovec iov;
@@ -219,8 +229,7 @@ static bool send_request(struct mgmt *mgmt, struct mgmt_request *request)
 
 	DBG(mgmt, "[0x%04x] command 0x%04x", request->index, request->opcode);
 
-	util_hexdump('<', request->buf, ret, mgmt->debug_callback,
-							mgmt->debug_data);
+	mgmt_hexdump(mgmt, '<', request->buf, ret);
 
 	queue_push_tail(mgmt->pending_list, request);
 
@@ -373,8 +382,7 @@ static bool can_read_data(struct io *io, void *user_data)
 	if (bytes_read < 0)
 		return false;
 
-	util_hexdump('>', mgmt->buf, bytes_read,
-				mgmt->debug_callback, mgmt->debug_data);
+	mgmt_hexdump(mgmt, '>', mgmt->buf, bytes_read);
 
 	if (bytes_read < MGMT_HDR_SIZE)
 		return true;
@@ -594,6 +602,14 @@ bool mgmt_set_debug(struct mgmt *mgmt, mgmt_debug_func_t callback,
 	return true;
 }
 
+void mgmt_set_verbose(struct mgmt *mgmt, bool value)
+{
+	if (!mgmt)
+		return;
+
+	mgmt->verbose = value;
+}
+
 bool mgmt_set_close_on_unref(struct mgmt *mgmt, bool do_close)
 {
 	if (!mgmt)
diff --git a/src/shared/mgmt.h b/src/shared/mgmt.h
index b413cea78..0f3e54c16 100644
--- a/src/shared/mgmt.h
+++ b/src/shared/mgmt.h
@@ -28,6 +28,7 @@ typedef void (*mgmt_debug_func_t)(const char *str, void *user_data);
 
 bool mgmt_set_debug(struct mgmt *mgmt, mgmt_debug_func_t callback,
 				void *user_data, mgmt_destroy_func_t destroy);
+void mgmt_set_verbose(struct mgmt *mgmt, bool value);
 
 bool mgmt_set_close_on_unref(struct mgmt *mgmt, bool do_close);
 
-- 
2.35.1

Re: [PATCH BlueZ v4 3/9] mgmt: Introduce mgmt_set_verbose

[Marcel Holtmann]

Hi Luiz,

> This introduces mgmt_set_verbose which can be used to enable printing
> the the likes hexdump of packets, by default it is disabled since in
> most cases the hexdump is not very useful and there are better tools
> to collect the hexdumo like btmon.
> ---
> src/shared/mgmt.c | 24 ++++++++++++++++++++----
> src/shared/mgmt.h |  1 +
> 2 files changed, 21 insertions(+), 4 deletions(-)
> 
> diff --git a/src/shared/mgmt.c b/src/shared/mgmt.c
> index c7e6a6c1d..cf518cc2b 100644
> --- a/src/shared/mgmt.c
> +++ b/src/shared/mgmt.c
> @@ -50,6 +50,7 @@ struct mgmt {
> 	mgmt_debug_func_t debug_callback;
> 	mgmt_destroy_func_t debug_destroy;
> 	void *debug_data;
> +	bool verbose;
> };
> 
> struct mgmt_request {
> @@ -192,6 +193,15 @@ static void mgmt_log(struct mgmt *mgmt, const char *format, ...)
> 	va_end(ap);
> }
> 
> +static void mgmt_hexdump(struct mgmt *mgmt, char dir, const void *data,
> +							size_t len)
> +{
> +	if (!mgmt->verbose)
> +		return;
> +
> +	util_hexdump(dir, data, len, mgmt->debug_callback, mgmt->debug_data);
> +}
> +

this is stupid, lets just remove the support for hexdump altogether here. This code was written when mgmt tracing via btmon was not available, but since it is now, there is really no point.

Regards

Marcel

[PATCH BlueZ v4 4/9] adapter: Don't use DBG in mgmt_debug

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

mgmt_debug callback is used to print debug strings from mgmt instances
which includes the file and function names so using DBG would add yet
another set of file and function prefixes which makes the logs
confusing.
---
 src/adapter.c | 7 ++-----
 1 file changed, 2 insertions(+), 5 deletions(-)

diff --git a/src/adapter.c b/src/adapter.c
index 97ce26f8e..9f003346d 100644
--- a/src/adapter.c
+++ b/src/adapter.c
@@ -10327,9 +10327,7 @@ static void read_version_complete(uint8_t status, uint16_t length,
 
 static void mgmt_debug(const char *str, void *user_data)
 {
-	const char *prefix = user_data;
-
-	info("%s%s", prefix, str);
+	DBG_IDX(0xffff, "%s", str);
 }
 
 int adapter_init(void)
@@ -10342,8 +10340,7 @@ int adapter_init(void)
 		return -EIO;
 	}
 
-	if (getenv("MGMT_DEBUG"))
-		mgmt_set_debug(mgmt_primary, mgmt_debug, "mgmt: ", NULL);
+	mgmt_set_debug(mgmt_primary, mgmt_debug, NULL, NULL);
 
 	DBG("sending read version command");
 
-- 
2.35.1

Re: [PATCH BlueZ v4 4/9] adapter: Don't use DBG in mgmt_debug

[Marcel Holtmann]

Hi Luiz,

> mgmt_debug callback is used to print debug strings from mgmt instances
> which includes the file and function names so using DBG would add yet
> another set of file and function prefixes which makes the logs
> confusing.
> ---
> src/adapter.c | 7 ++-----
> 1 file changed, 2 insertions(+), 5 deletions(-)
> 
> diff --git a/src/adapter.c b/src/adapter.c
> index 97ce26f8e..9f003346d 100644
> --- a/src/adapter.c
> +++ b/src/adapter.c
> @@ -10327,9 +10327,7 @@ static void read_version_complete(uint8_t status, uint16_t length,
> 
> static void mgmt_debug(const char *str, void *user_data)
> {
> -	const char *prefix = user_data;
> -
> -	info("%s%s", prefix, str);
> +	DBG_IDX(0xffff, "%s", str);
> }
> 
> int adapter_init(void)
> @@ -10342,8 +10340,7 @@ int adapter_init(void)
> 		return -EIO;
> 	}
> 
> -	if (getenv("MGMT_DEBUG"))
> -		mgmt_set_debug(mgmt_primary, mgmt_debug, "mgmt: ", NULL);
> +	mgmt_set_debug(mgmt_primary, mgmt_debug, NULL, NULL);
> 
> 	DBG("sending read version command");

oh what now. If you touch this, then please do it in a way that you print it properly to the btmon traces as well with the correct index.

Look, the MGMT_DEBUG thing is meant for debugging aid. That is why it enabled tracing. If you want to print errors or warning that otherwise are hidden, just print them. And make sure they end up in btmon as well. This is all hacking around the real solution. It is a bandaid for a bandaid.

Regards

Marcel

[PATCH BlueZ v4 5/9] att: Log file and function names

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This adds logging of file and function names.
---
 src/shared/att.c | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/src/shared/att.c b/src/shared/att.c
index 169f726e4..7344b0c46 100644
--- a/src/shared/att.c
+++ b/src/shared/att.c
@@ -308,10 +308,12 @@ static void att_log(struct bt_att *att, uint8_t level, const char *format,
 }
 
 #define att_debug(_att, _format, _arg...) \
-	att_log(_att, BT_ATT_DEBUG, _format, ## _arg)
+	att_log(_att, BT_ATT_DEBUG, "%s:%s() " _format, __FILE__, __func__,\
+		## _arg)
 
 #define att_verbose(_att, _format, _arg...) \
-	att_log(_att, BT_ATT_DEBUG_VERBOSE, _format, ## _arg)
+	att_log(_att, BT_ATT_DEBUG_VERBOSE, "%s:%s() " _format, __FILE__, \
+		__func__, ## _arg)
 
 static void att_hexdump(struct bt_att *att, char dir, const void *data,
 							size_t len)
-- 
2.35.1

[PATCH BlueZ v4 6/9] gatt-client: Add DBG macro

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This adds gatt_log wrapper for util_debug and DBG macro so file and
function names are printed which is more consistent with other parts of
the daemon code.
---
 src/shared/gatt-client.c | 160 +++++++++++++++++----------------------
 1 file changed, 70 insertions(+), 90 deletions(-)

diff --git a/src/shared/gatt-client.c b/src/shared/gatt-client.c
index e24c9603c..ba9228ddf 100644
--- a/src/shared/gatt-client.c
+++ b/src/shared/gatt-client.c
@@ -37,6 +37,8 @@
 
 #define GATT_SVC_UUID	0x1801
 #define SVC_CHNGD_UUID	0x2a05
+#define DBG(_client, _format, arg...) \
+	gatt_log(_client, "%s:%s() " _format, __FILE__, __func__, ## arg)
 
 struct ready_cb {
 	bt_gatt_client_callback_t callback;
@@ -376,6 +378,18 @@ static void discovery_op_free(struct discovery_op *op)
 
 static bool read_db_hash(struct discovery_op *op);
 
+static void gatt_log(struct bt_gatt_client *client, const char *format, ...)
+{
+	va_list ap;
+
+	if (!client || !format || !client->debug_callback)
+		return;
+
+	va_start(ap, format);
+	util_debug_va(client->debug_callback, client->debug_data, format, ap);
+	va_end(ap);
+}
+
 static void discovery_op_complete(struct discovery_op *op, bool success,
 								uint8_t err)
 {
@@ -406,9 +420,8 @@ static void discovery_op_complete(struct discovery_op *op, bool success,
 		gatt_db_attribute_get_service_data(attr, &start, &end,
 							NULL, NULL);
 
-		util_debug(op->client->debug_callback, op->client->debug_data,
-				"service disappeared: start 0x%04x end 0x%04x",
-				start, end);
+		DBG(op->client, "service disappeared: start 0x%04x end 0x%04x",
+			start, end);
 
 		gatt_db_remove_service(op->client->db, attr);
 	}
@@ -542,9 +555,7 @@ static void discover_incl_cb(bool success, uint8_t att_ecode,
 	if (includes_count == 0)
 		goto failed;
 
-	util_debug(client->debug_callback, client->debug_data,
-						"Included services found: %u",
-						includes_count);
+	DBG(client, "Included services found: %u", includes_count);
 
 	for (i = 0; i < includes_count; i++) {
 		if (!bt_gatt_iter_next_included_service(&iter, &handle, &start,
@@ -555,13 +566,12 @@ static void discover_incl_cb(bool success, uint8_t att_ecode,
 
 		/* Log debug message */
 		bt_uuid_to_string(&uuid, uuid_str, sizeof(uuid_str));
-		util_debug(client->debug_callback, client->debug_data,
-				"handle: 0x%04x, start: 0x%04x, end: 0x%04x,"
+		DBG(client, "handle: 0x%04x, start: 0x%04x, end: 0x%04x,"
 				"uuid: %s", handle, start, end, uuid_str);
 
 		attr = gatt_db_get_attribute(client->db, start);
 		if (!attr) {
-			util_debug(client->debug_callback, client->debug_data,
+			DBG(client,
 				"Unable to find attribute at 0x%04x: skipping",
 				start);
 			continue;
@@ -569,7 +579,7 @@ static void discover_incl_cb(bool success, uint8_t att_ecode,
 
 		attr = gatt_db_insert_included(client->db, handle, attr);
 		if (!attr) {
-			util_debug(client->debug_callback, client->debug_data,
+			DBG(client,
 				"Unable to add include attribute at 0x%04x",
 				handle);
 			goto failed;
@@ -582,7 +592,7 @@ static void discover_incl_cb(bool success, uint8_t att_ecode,
 		 * attribute.
 		 */
 		if (gatt_db_attribute_get_handle(attr) != handle) {
-			util_debug(client->debug_callback, client->debug_data,
+			DBG(client,
 				"Invalid attribute 0x%04x expect it at 0x%04x",
 				gatt_db_attribute_get_handle(attr), handle);
 			goto failed;
@@ -604,8 +614,8 @@ next:
 	if (client->discovery_req)
 		return;
 
-	util_debug(client->debug_callback, client->debug_data,
-				"Failed to start characteristic discovery");
+	DBG(client, "Failed to start characteristic discovery");
+
 	discovery_op_unref(op);
 failed:
 	discovery_op_complete(op, false, att_ecode);
@@ -656,7 +666,7 @@ static bool discover_descs(struct discovery_op *op, bool *discovering)
 							NULL, NULL, NULL);
 
 		if (!attr) {
-			util_debug(client->debug_callback, client->debug_data,
+			DBG(client,
 				"Failed to insert characteristic at 0x%04x",
 				chrc_data->value_handle);
 
@@ -729,8 +739,8 @@ static bool discover_descs(struct discovery_op *op, bool *discovering)
 			goto done;
 		}
 
-		util_debug(client->debug_callback, client->debug_data,
-					"Failed to start descriptor discovery");
+		DBG(client, "Failed to start descriptor discovery");
+
 		discovery_op_unref(op);
 
 		goto failed;
@@ -750,8 +760,7 @@ static void ext_prop_write_cb(struct gatt_db_attribute *attrib,
 {
 	struct bt_gatt_client *client = user_data;
 
-	util_debug(client->debug_callback, client->debug_data,
-						"Value set status: %d", err);
+	DBG(client, "Value set status: %d", err);
 }
 
 static void ext_prop_read_cb(bool success, uint8_t att_ecode,
@@ -790,8 +799,7 @@ static void ext_prop_read_cb(bool success, uint8_t att_ecode,
 	if (!success)
 		goto done;
 
-	util_debug(client->debug_callback, client->debug_data,
-				"Ext. prop value: 0x%04x", (uint16_t)value[0]);
+	DBG(client, "Ext. prop value: 0x%04x", (uint16_t)value[0]);
 
 	desc_attr = queue_pop_head(op->ext_prop_desc);
 	if (!desc_attr)
@@ -857,8 +865,7 @@ static void discover_descs_cb(bool success, uint8_t att_ecode,
 	if (desc_count == 0)
 		goto failed;
 
-	util_debug(client->debug_callback, client->debug_data,
-					"Descriptors found: %u", desc_count);
+	DBG(client, "Descriptors found: %u", desc_count);
 
 	bt_uuid16_create(&ext_prop_uuid, GATT_CHARAC_EXT_PROPER_UUID);
 
@@ -867,9 +874,8 @@ static void discover_descs_cb(bool success, uint8_t att_ecode,
 
 		/* Log debug message */
 		bt_uuid_to_string(&uuid, uuid_str, sizeof(uuid_str));
-		util_debug(client->debug_callback, client->debug_data,
-						"handle: 0x%04x, uuid: %s",
-						handle, uuid_str);
+
+		DBG(client, "handle: 0x%04x, uuid: %s", handle, uuid_str);
 
 		attr = gatt_db_insert_descriptor(client->db, handle,
 							&uuid, 0, NULL, NULL,
@@ -880,8 +886,7 @@ static void discover_descs_cb(bool success, uint8_t att_ecode,
 					gatt_db_attribute_get_type(attr)))
 				continue;
 
-			util_debug(client->debug_callback, client->debug_data,
-				"Failed to insert descriptor at 0x%04x",
+			DBG(client, "Failed to insert descriptor at 0x%04x",
 				handle);
 			goto failed;
 		}
@@ -947,8 +952,8 @@ static void discover_chrcs_cb(bool success, uint8_t att_ecode,
 		goto failed;
 
 	chrc_count = bt_gatt_result_characteristic_count(result);
-	util_debug(client->debug_callback, client->debug_data,
-				"Characteristics found: %u", chrc_count);
+
+	DBG(client, "Characteristics found: %u", chrc_count);
 
 	if (chrc_count == 0)
 		goto failed;
@@ -959,8 +964,7 @@ static void discover_chrcs_cb(bool success, uint8_t att_ecode,
 
 		/* Log debug message */
 		bt_uuid_to_string(&uuid, uuid_str, sizeof(uuid_str));
-		util_debug(client->debug_callback, client->debug_data,
-				"start: 0x%04x, end: 0x%04x, value: 0x%04x, "
+		DBG(client, "start: 0x%04x, end: 0x%04x, value: 0x%04x, "
 				"props: 0x%02x, uuid: %s",
 				start, end, value, properties, uuid_str);
 
@@ -997,8 +1001,7 @@ next:
 		if (client->discovery_req)
 			return;
 
-		util_debug(client->debug_callback, client->debug_data,
-				"Failed to start included services discovery");
+		DBG(client, "Failed to start included services discovery");
 
 		discovery_op_unref(op);
 
@@ -1110,8 +1113,7 @@ static bool discovery_parse_services(struct discovery_op *op, bool primary,
 
 		/* Log debug message */
 		bt_uuid_to_string(&uuid, uuid_str, sizeof(uuid_str));
-		util_debug(client->debug_callback, client->debug_data,
-				"start: 0x%04x, end: 0x%04x, uuid: %s",
+		DBG(client, "start: 0x%04x, end: 0x%04x, uuid: %s",
 				start, end, uuid_str);
 
 		/* Store the service */
@@ -1122,9 +1124,7 @@ static bool discovery_parse_services(struct discovery_op *op, bool primary,
 			attr = gatt_db_insert_service(client->db, start, &uuid,
 							false, end - start + 1);
 			if (!attr) {
-				util_debug(client->debug_callback,
-						client->debug_data,
-						"Failed to store service");
+				DBG(client, "Failed to store service");
 				return false;
 			}
 			/* Database has changed adjust last handle */
@@ -1157,8 +1157,7 @@ static void discover_secondary_cb(bool success, uint8_t att_ecode,
 			att_ecode = 0;
 			goto next;
 		default:
-			util_debug(client->debug_callback, client->debug_data,
-					"Secondary service discovery failed."
+			DBG(client, "Secondary service discovery failed."
 					" ATT ECODE: 0x%02x", att_ecode);
 			goto done;
 		}
@@ -1169,8 +1168,7 @@ static void discover_secondary_cb(bool success, uint8_t att_ecode,
 		goto done;
 	}
 
-	util_debug(client->debug_callback, client->debug_data,
-					"Secondary services found: %u",
+	DBG(client, "Secondary services found: %u",
 					bt_gatt_result_service_count(result));
 
 	if (!discovery_parse_services(op, false, &iter)) {
@@ -1199,8 +1197,8 @@ next:
 	if (client->discovery_req)
 		return;
 
-	util_debug(client->debug_callback, client->debug_data,
-				"Failed to start included services discovery");
+	DBG(client, "Failed to start included services discovery");
+
 	discovery_op_unref(op);
 	success = false;
 
@@ -1226,8 +1224,7 @@ static void discover_primary_cb(bool success, uint8_t att_ecode,
 			att_ecode = 0;
 			goto secondary;
 		default:
-			util_debug(client->debug_callback, client->debug_data,
-					"Primary service discovery failed."
+			DBG(client, "Primary service discovery failed."
 					" ATT ECODE: 0x%02x", att_ecode);
 			goto done;
 		}
@@ -1238,8 +1235,7 @@ static void discover_primary_cb(bool success, uint8_t att_ecode,
 		goto done;
 	}
 
-	util_debug(client->debug_callback, client->debug_data,
-					"Primary services found: %u",
+	DBG(client, "Primary services found: %u",
 					bt_gatt_result_service_count(result));
 
 	if (!discovery_parse_services(op, true, &iter)) {
@@ -1266,8 +1262,8 @@ secondary:
 	if (client->discovery_req)
 		return;
 
-	util_debug(client->debug_callback, client->debug_data,
-				"Failed to start secondary service discovery");
+	DBG(client, "Failed to start secondary service discovery");
+
 	discovery_op_unref(op);
 	success = false;
 
@@ -1331,8 +1327,7 @@ static void discover_all(struct discovery_op *op)
 	if (client->discovery_req)
 		return;
 
-	util_debug(client->debug_callback, client->debug_data,
-			"Failed to initiate primary service discovery");
+	DBG(client, "Failed to initiate primary service discovery");
 
 	client->in_init = false;
 	notify_client_ready(client, false, BT_ATT_ERROR_UNLIKELY);
@@ -1345,8 +1340,7 @@ static void db_hash_write_value_cb(struct gatt_db_attribute *attrib,
 {
 	struct bt_gatt_client *client = user_data;
 
-	util_debug(client->debug_callback, client->debug_data,
-						"Value set status: %d", err);
+	DBG(client, "Value set status: %d", err);
 }
 
 static void db_hash_read_value_cb(struct gatt_db_attribute *attrib,
@@ -1377,9 +1371,8 @@ static void db_hash_read_cb(bool success, uint8_t att_ecode,
 	bt_gatt_iter_init(&iter, result);
 	bt_gatt_iter_next_read_by_type(&iter, &handle, &len, &value);
 
-	util_debug(client->debug_callback, client->debug_data,
-				"DB Hash found: handle 0x%04x length 0x%04x",
-				handle, len);
+	DBG(client, "DB Hash found: handle 0x%04x length 0x%04x",
+							handle, len);
 
 	if (len != 16)
 		goto discover;
@@ -1390,15 +1383,14 @@ static void db_hash_read_cb(bool success, uint8_t att_ecode,
 
 	/* Check if the has has changed since last time */
 	if (hash && !memcmp(hash, value, len)) {
-		util_debug(client->debug_callback, client->debug_data,
-				"DB Hash match: skipping discovery");
+		DBG(client, "DB Hash match: skipping discovery");
 		queue_remove_all(op->pending_svcs, NULL, NULL, NULL);
 		discovery_op_complete(op, true, 0);
 		return;
 	}
 
-	util_debug(client->debug_callback, client->debug_data,
-						"DB Hash value:");
+	DBG(client, "DB Hash value:");
+
 	util_hexdump(' ', value, len, client->debug_callback,
 						client->debug_data);
 
@@ -1469,8 +1461,7 @@ static void db_server_feat_read(bool success, uint8_t att_ecode,
 	bt_gatt_iter_init(&iter, result);
 	bt_gatt_iter_next_read_by_type(&iter, &handle, &len, &value);
 
-	util_debug(client->debug_callback, client->debug_data,
-				"Server Features found: handle 0x%04x "
+	DBG(client, "Server Features found: handle 0x%04x "
 				"length 0x%04x value 0x%02x", handle, len,
 				value[0]);
 
@@ -1524,8 +1515,7 @@ static void exchange_mtu_cb(bool success, uint8_t att_ecode, void *user_data)
 	client->mtu_req_id = 0;
 
 	if (!success) {
-		util_debug(client->debug_callback, client->debug_data,
-				"MTU Exchange failed. ATT ECODE: 0x%02x",
+		DBG(client, "MTU Exchange failed. ATT ECODE: 0x%02x",
 				att_ecode);
 
 		/*
@@ -1543,8 +1533,7 @@ static void exchange_mtu_cb(bool success, uint8_t att_ecode, void *user_data)
 		return;
 	}
 
-	util_debug(client->debug_callback, client->debug_data,
-					"MTU exchange complete, with MTU: %u",
+	DBG(client, "MTU exchange complete, with MTU: %u",
 					bt_att_get_mtu(client->att));
 
 discover:
@@ -1749,7 +1738,7 @@ static void service_changed_register_cb(uint16_t att_ecode, void *user_data)
 	struct bt_gatt_client *client = user_data;
 
 	if (att_ecode) {
-		util_debug(client->debug_callback, client->debug_data,
+		DBG(client,
 			"Failed to register handler for \"Service Changed\"");
 		success = false;
 		client->svc_chngd_ind_id = 0;
@@ -1758,8 +1747,7 @@ static void service_changed_register_cb(uint16_t att_ecode, void *user_data)
 
 	client->svc_chngd_registered = true;
 	success = true;
-	util_debug(client->debug_callback, client->debug_data,
-			"Registered handler for \"Service Changed\": %u",
+	DBG(client, "Registered handler for \"Service Changed\": %u",
 			client->svc_chngd_ind_id);
 
 done:
@@ -1807,7 +1795,7 @@ static void service_changed_complete(struct discovery_op *op, bool success,
 	client->in_svc_chngd = false;
 
 	if (!success && att_ecode != BT_ATT_ERROR_ATTRIBUTE_NOT_FOUND) {
-		util_debug(client->debug_callback, client->debug_data,
+		DBG(client,
 			"Failed to discover services within changed range - "
 			"error: 0x%02x", att_ecode);
 
@@ -1841,7 +1829,7 @@ static void service_changed_complete(struct discovery_op *op, bool success,
 	if (register_service_changed(client))
 		return;
 
-	util_debug(client->debug_callback, client->debug_data,
+	DBG(client,
 		"Failed to re-register handler for \"Service Changed\"");
 }
 
@@ -1877,9 +1865,8 @@ static void process_service_changed(struct bt_gatt_client *client,
 	discovery_op_free(op);
 
 fail:
-	util_debug(client->debug_callback, client->debug_data,
-					"Failed to initiate service discovery"
-					" after Service Changed");
+	DBG(client,
+		"Failed to initiate service discovery after Service Changed");
 }
 
 static void service_changed_cb(uint16_t value_handle, const uint8_t *value,
@@ -1896,13 +1883,12 @@ static void service_changed_cb(uint16_t value_handle, const uint8_t *value,
 	end = get_le16(value + 2);
 
 	if (start > end) {
-		util_debug(client->debug_callback, client->debug_data,
+		DBG(client,
 			"Service Changed received with invalid handles");
 		return;
 	}
 
-	util_debug(client->debug_callback, client->debug_data,
-			"Service Changed received - start: 0x%04x end: 0x%04x",
+	DBG(client, "Service Changed received - start: 0x%04x end: 0x%04x",
 			start, end);
 
 	if (!client->in_svc_chngd) {
@@ -1923,8 +1909,7 @@ static void server_feat_write_value(struct gatt_db_attribute *attrib,
 {
 	struct bt_gatt_client *client = user_data;
 
-	util_debug(client->debug_callback, client->debug_data,
-			"Server Features Value set status: %d", err);
+	DBG(client, "Server Features Value set status: %d", err);
 }
 
 static void write_server_features(struct bt_gatt_client *client, uint8_t feat)
@@ -1943,8 +1928,7 @@ static void write_server_features(struct bt_gatt_client *client, uint8_t feat)
 	if (!gatt_db_attribute_write(attr, 0, &feat, sizeof(feat),
 					0, NULL, server_feat_write_value,
 					client))
-		util_debug(client->debug_callback, client->debug_data,
-					"Unable to store Server Features");
+		DBG(client, "Unable to store Server Features");
 }
 
 static void write_client_features(struct bt_gatt_client *client)
@@ -1981,8 +1965,7 @@ static void write_client_features(struct bt_gatt_client *client)
 
 	client->features |= BT_GATT_CHRC_CLI_FEAT_NFY_MULTI;
 
-	util_debug(client->debug_callback, client->debug_data,
-			"Writing Client Features 0x%02x", client->features);
+	DBG(client, "Writing Client Features 0x%02x", client->features);
 
 	bt_gatt_client_write_value(client, handle, &client->features,
 				sizeof(client->features), NULL, NULL, NULL);
@@ -2006,13 +1989,11 @@ static void init_complete(struct discovery_op *op, bool success,
 	if (register_service_changed(client))
 		goto done;
 
-	util_debug(client->debug_callback, client->debug_data,
-			"Failed to register handler for \"Service Changed\"");
+	DBG(client, "Failed to register handler for \"Service Changed\"");
 	success = false;
 
 fail:
-	util_debug(client->debug_callback, client->debug_data,
-			"Failed to initialize gatt-client");
+	DBG(client, "Failed to initialize gatt-client");
 
 	op->success = false;
 
@@ -3501,8 +3482,7 @@ unsigned int bt_gatt_client_prepare_write(struct bt_gatt_client *client,
 	 * prepare writes or this is brand new reliable session (id == 0)
 	 */
 	if (id != client->reliable_write_session_id) {
-		util_debug(client->debug_callback, client->debug_data,
-			"There is other reliable write session ongoing %u",
+		DBG(client, "There is other reliable write session ongoing %u",
 			client->reliable_write_session_id);
 
 		return 0;
-- 
2.35.1

[PATCH BlueZ v4 7/9] gatt-server: Add DBG macro

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This adds gatt_log wrapper for util_debug and DBG so file and function
names are printed with the logs.
---
 src/shared/gatt-server.c | 64 ++++++++++++++++++++--------------------
 1 file changed, 32 insertions(+), 32 deletions(-)

diff --git a/src/shared/gatt-server.c b/src/shared/gatt-server.c
index 776e5ce2b..2adb4afbf 100644
--- a/src/shared/gatt-server.c
+++ b/src/shared/gatt-server.c
@@ -41,6 +41,9 @@
 
 #define NFY_MULT_TIMEOUT 10
 
+#define DBG(_server, _format, arg...) \
+	gatt_log(_server, "%s:%s() " _format, __FILE__, __func__, ## arg)
+
 struct async_read_op {
 	struct bt_att_chan *chan;
 	struct bt_gatt_server *server;
@@ -233,6 +236,18 @@ static bool encode_read_by_grp_type_rsp(struct gatt_db *db, struct queue *q,
 	return true;
 }
 
+static void gatt_log(struct bt_gatt_server *server, const char *format, ...)
+{
+	va_list ap;
+
+	if (!server || !format || !server->debug_callback)
+		return;
+
+	va_start(ap, format);
+	util_debug_va(server->debug_callback, server->debug_data, format, ap);
+	va_end(ap);
+}
+
 static void read_by_grp_type_cb(struct bt_att_chan *chan, uint8_t opcode,
 					const void *pdu, uint16_t length,
 					void *user_data)
@@ -259,9 +274,7 @@ static void read_by_grp_type_cb(struct bt_att_chan *chan, uint8_t opcode,
 	end = get_le16(pdu + 2);
 	get_uuid_le(pdu + 4, length - 4, &type);
 
-	util_debug(server->debug_callback, server->debug_data,
-				"Read By Grp Type - start: 0x%04x end: 0x%04x",
-				start, end);
+	DBG(server, "Read By Grp Type - start: 0x%04x end: 0x%04x", start, end);
 
 	if (!start || !end) {
 		ecode = BT_ATT_ERROR_INVALID_HANDLE;
@@ -483,9 +496,7 @@ static void read_by_type_cb(struct bt_att_chan *chan, uint8_t opcode,
 	end = get_le16(pdu + 2);
 	get_uuid_le(pdu + 4, length - 4, &type);
 
-	util_debug(server->debug_callback, server->debug_data,
-				"Read By Type - start: 0x%04x end: 0x%04x",
-				start, end);
+	DBG(server, "Read By Type - start: 0x%04x end: 0x%04x", start, end);
 
 	if (!start || !end) {
 		ecode = BT_ATT_ERROR_INVALID_HANDLE;
@@ -605,9 +616,7 @@ static void find_info_cb(struct bt_att_chan *chan, uint8_t opcode,
 	start = get_le16(pdu);
 	end = get_le16(pdu + 2);
 
-	util_debug(server->debug_callback, server->debug_data,
-					"Find Info - start: 0x%04x end: 0x%04x",
-					start, end);
+	DBG(server, "Find Info - start: 0x%04x end: 0x%04x", start, end);
 
 	if (!start || !end) {
 		ecode = BT_ATT_ERROR_INVALID_HANDLE;
@@ -708,9 +717,10 @@ static void find_by_type_val_cb(struct bt_att_chan *chan, uint8_t opcode,
 	end = get_le16(pdu + 2);
 	uuid16 = get_le16(pdu + 4);
 
-	util_debug(server->debug_callback, server->debug_data,
-			"Find By Type Value - start: 0x%04x end: 0x%04x uuid: 0x%04x",
-			start, end, uuid16);
+	DBG(server,
+	    "Find By Type Value - start: 0x%04x end: 0x%04x uuid: 0x%04x",
+	    start, end, uuid16);
+
 	ehandle = start;
 	if (start > end) {
 		data.ecode = BT_ATT_ERROR_INVALID_HANDLE;
@@ -756,8 +766,7 @@ static void write_complete_cb(struct gatt_db_attribute *attr, int err,
 		return;
 	}
 
-	util_debug(server->debug_callback, server->debug_data,
-						"Write Complete: err %d", err);
+	DBG(server, "Write Complete: err %d", err);
 
 	handle = gatt_db_attribute_get_handle(attr);
 
@@ -818,10 +827,8 @@ static void write_cb(struct bt_att_chan *chan, uint8_t opcode, const void *pdu,
 		goto error;
 	}
 
-	util_debug(server->debug_callback, server->debug_data,
-				"Write %s - handle: 0x%04x",
-				(opcode == BT_ATT_OP_WRITE_REQ) ? "Req" : "Cmd",
-				handle);
+	DBG(server, "Write %s - handle: 0x%04x",
+		(opcode == BT_ATT_OP_WRITE_REQ) ? "Req" : "Cmd", handle);
 
 	ecode = check_length(length, 0);
 	if (ecode)
@@ -885,8 +892,7 @@ static void read_complete_cb(struct gatt_db_attribute *attr, int err,
 	uint16_t mtu;
 	uint16_t handle;
 
-	util_debug(server->debug_callback, server->debug_data,
-				"Read Complete: err %d", err);
+	DBG(server, "Read Complete: err %d", err);
 
 	mtu = bt_att_get_mtu(server->att);
 	handle = gatt_db_attribute_get_handle(attr);
@@ -922,10 +928,8 @@ static void handle_read_req(struct bt_att_chan *chan,
 		goto error;
 	}
 
-	util_debug(server->debug_callback, server->debug_data,
-			"Read %sReq - handle: 0x%04x",
-			opcode == BT_ATT_OP_READ_BLOB_REQ ? "Blob " : "",
-			handle);
+	DBG(server, "Read %sReq - handle: 0x%04x",
+		opcode == BT_ATT_OP_READ_BLOB_REQ ? "Blob " : "", handle);
 
 	ecode = check_permissions(server, attr, BT_ATT_PERM_READ_MASK);
 	if (ecode)
@@ -1125,8 +1129,7 @@ static void read_multiple_cb(struct bt_att_chan *chan, uint8_t opcode,
 
 	handle = data->handles[0];
 
-	util_debug(server->debug_callback, server->debug_data,
-			"%s Req - %zu handles, 1st: 0x%04x",
+	DBG(server, "%s Req - %zu handles, 1st: 0x%04x",
 			data->opcode == BT_ATT_OP_READ_MULT_REQ ?
 			"Read Multiple" : "Read Multiple Variable Length",
 			data->num_handles, handle);
@@ -1312,8 +1315,7 @@ static void prep_write_cb(struct bt_att_chan *chan, uint8_t opcode,
 		goto error;
 	}
 
-	util_debug(server->debug_callback, server->debug_data,
-				"Prep Write Req - handle: 0x%04x", handle);
+	DBG(server, "Prep Write Req - handle: 0x%04x", handle);
 
 	ecode = check_length(length, offset);
 	if (ecode)
@@ -1433,8 +1435,7 @@ static void exec_write_cb(struct bt_att_chan *chan, uint8_t opcode,
 
 	flags = ((uint8_t *) pdu)[0];
 
-	util_debug(server->debug_callback, server->debug_data,
-				"Exec Write Req - flags: 0x%02x", flags);
+	DBG(server, "Exec Write Req - flags: 0x%02x", flags);
 
 	if (flags == 0x00)
 		write = false;
@@ -1505,8 +1506,7 @@ static void exchange_mtu_cb(struct bt_att_chan *chan, uint8_t opcode,
 	server->mtu = final_mtu;
 	bt_att_set_mtu(server->att, final_mtu);
 
-	util_debug(server->debug_callback, server->debug_data,
-			"MTU exchange complete, with MTU: %u", final_mtu);
+	DBG(server, "MTU exchange complete, with MTU: %u", final_mtu);
 }
 
 static bool gatt_server_register_att_handlers(struct bt_gatt_server *server)
-- 
2.35.1

[PATCH BlueZ v4 8/9] att: Rename att_debug and att_verbose to DBG and VERBOSE

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

att_debug and att_verbose are macros which are more common to be
used as uppercase, this also change them to use DBG like other parts of
the code.
---
 src/shared/att.c | 38 +++++++++++++++++++-------------------
 1 file changed, 19 insertions(+), 19 deletions(-)

diff --git a/src/shared/att.c b/src/shared/att.c
index 7344b0c46..f7bef08bc 100644
--- a/src/shared/att.c
+++ b/src/shared/att.c
@@ -307,11 +307,11 @@ static void att_log(struct bt_att *att, uint8_t level, const char *format,
 	va_end(va);
 }
 
-#define att_debug(_att, _format, _arg...) \
+#define DBG(_att, _format, _arg...) \
 	att_log(_att, BT_ATT_DEBUG, "%s:%s() " _format, __FILE__, __func__,\
 		## _arg)
 
-#define att_verbose(_att, _format, _arg...) \
+#define VERBOSE(_att, _format, _arg...) \
 	att_log(_att, BT_ATT_DEBUG_VERBOSE, "%s:%s() " _format, __FILE__, \
 		__func__, ## _arg)
 
@@ -359,7 +359,7 @@ static bool encode_pdu(struct bt_att *att, struct att_send_op *op,
 				sign_cnt, &((uint8_t *) op->pdu)[1 + length])))
 		return true;
 
-	att_debug(att, "ATT unable to generate signature");
+	DBG(att, "ATT unable to generate signature");
 
 fail:
 	free(op->pdu);
@@ -488,7 +488,7 @@ static bool timeout_cb(void *user_data)
 	if (!op)
 		return false;
 
-	att_debug(att, "(chan %p) Operation timed out: 0x%02x", chan,
+	DBG(att, "(chan %p) Operation timed out: 0x%02x", chan,
 						op->opcode);
 
 	if (att->timeout_callback)
@@ -524,11 +524,11 @@ static ssize_t bt_att_chan_write(struct bt_att_chan *chan, uint8_t opcode,
 	iov.iov_base = (void *) pdu;
 	iov.iov_len = len;
 
-	att_verbose(att, "(chan %p) ATT op 0x%02x", chan, opcode);
+	VERBOSE(att, "(chan %p) ATT op 0x%02x", chan, opcode);
 
 	ret = io_send(chan->io, &iov, 1);
 	if (ret < 0) {
-		att_debug(att, "(chan %p) write failed: %s", chan,
+		DBG(att, "(chan %p) write failed: %s", chan,
 						strerror(-ret));
 		return ret;
 	}
@@ -661,12 +661,12 @@ static bool disconnect_cb(struct io *io, void *user_data)
 	len = sizeof(err);
 
 	if (getsockopt(chan->fd, SOL_SOCKET, SO_ERROR, &err, &len) < 0) {
-		att_debug(att, "(chan %p) Failed to obtain disconnect "
+		DBG(att, "(chan %p) Failed to obtain disconnect "
 				"error: %s", chan, strerror(errno));
 		err = 0;
 	}
 
-	att_debug(att, "Channel %p disconnected: %s", chan, strerror(err));
+	DBG(att, "Channel %p disconnected: %s", chan, strerror(err));
 
 	/* Dettach channel */
 	queue_remove(att->chans, chan);
@@ -795,7 +795,7 @@ static bool handle_error_rsp(struct bt_att_chan *chan, uint8_t *pdu,
 		op->timeout_id = 0;
 	}
 
-	att_debug(att, "(chan %p) Retrying operation %p", chan, op);
+	DBG(att, "(chan %p) Retrying operation %p", chan, op);
 
 	chan->pending_req = NULL;
 
@@ -818,7 +818,7 @@ static void handle_rsp(struct bt_att_chan *chan, uint8_t opcode, uint8_t *pdu,
 	 * the bearer.
 	 */
 	if (!op) {
-		att_debug(att, "(chan %p) Received unexpected ATT response",
+		DBG(att, "(chan %p) Received unexpected ATT response",
 								chan);
 		io_shutdown(chan->io);
 		return;
@@ -850,7 +850,7 @@ static void handle_rsp(struct bt_att_chan *chan, uint8_t opcode, uint8_t *pdu,
 	goto done;
 
 fail:
-	att_debug(att, "(chan %p) Failed to handle response PDU; opcode: "
+	DBG(att, "(chan %p) Failed to handle response PDU; opcode: "
 			"0x%02x", chan, opcode);
 
 	rsp_opcode = BT_ATT_OP_ERROR_RSP;
@@ -875,7 +875,7 @@ static void handle_conf(struct bt_att_chan *chan, uint8_t *pdu, ssize_t pdu_len)
 	 * invalid.
 	 */
 	if (!op || pdu_len) {
-		att_debug(att, "(chan %p) Received unexpected/invalid ATT "
+		DBG(att, "(chan %p) Received unexpected/invalid ATT "
 				"confirmation", chan);
 		io_shutdown(chan->io);
 		return;
@@ -949,7 +949,7 @@ static bool handle_signed(struct bt_att *att, uint8_t *pdu, ssize_t pdu_len)
 	return true;
 
 fail:
-	att_debug(att, "ATT failed to verify signature: 0x%02x", opcode);
+	DBG(att, "ATT failed to verify signature: 0x%02x", opcode);
 
 	return false;
 }
@@ -1032,7 +1032,7 @@ static bool can_read_data(struct io *io, void *user_data)
 	if (bytes_read < 0)
 		return false;
 
-	att_verbose(att, "(chan %p) ATT received: %zd", chan, bytes_read);
+	VERBOSE(att, "(chan %p) ATT received: %zd", chan, bytes_read);
 
 	att_hexdump(att, '>', chan->buf, bytes_read);
 
@@ -1047,12 +1047,12 @@ static bool can_read_data(struct io *io, void *user_data)
 	/* Act on the received PDU based on the opcode type */
 	switch (get_op_type(opcode)) {
 	case ATT_OP_TYPE_RSP:
-		att_verbose(att, "(chan %p) ATT response received: 0x%02x",
+		VERBOSE(att, "(chan %p) ATT response received: 0x%02x",
 				chan, opcode);
 		handle_rsp(chan, opcode, pdu + 1, bytes_read - 1);
 		break;
 	case ATT_OP_TYPE_CONF:
-		att_verbose(att, "(chan %p) ATT confirmation received: 0x%02x",
+		VERBOSE(att, "(chan %p) ATT confirmation received: 0x%02x",
 				chan, opcode);
 		handle_conf(chan, pdu + 1, bytes_read - 1);
 		break;
@@ -1063,7 +1063,7 @@ static bool can_read_data(struct io *io, void *user_data)
 		 * promptly notify the upper layer via disconnect handlers.
 		 */
 		if (chan->in_req) {
-			att_debug(att, "(chan %p) Received request while "
+			DBG(att, "(chan %p) Received request while "
 					"another is pending: 0x%02x",
 					chan, opcode);
 			io_shutdown(chan->io);
@@ -1083,7 +1083,7 @@ static bool can_read_data(struct io *io, void *user_data)
 		/* For all other opcodes notify the upper layer of the PDU and
 		 * let them act on it.
 		 */
-		att_debug(att, "(chan %p) ATT PDU received: 0x%02x", chan,
+		DBG(att, "(chan %p) ATT PDU received: 0x%02x", chan,
 							opcode);
 		handle_notify(chan, pdu, bytes_read);
 		break;
@@ -1237,7 +1237,7 @@ static void bt_att_attach_chan(struct bt_att *att, struct bt_att_chan *chan)
 
 	io_set_close_on_destroy(chan->io, att->close_on_unref);
 
-	att_debug(att, "Channel %p attached", chan);
+	DBG(att, "Channel %p attached", chan);
 
 	wakeup_chan_writer(chan, NULL);
 }
-- 
2.35.1

[PATCH BlueZ v4 9/9] device: Don't use DBG in gatt_debug

[Luiz Augusto von Dentz]

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

gatt_debug callback is used to print debug strings from bt_att which
includes the file and function names so using DBG would add yet another
set of file and function prefixes which makes the logs confusing.
---
 src/device.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/device.c b/src/device.c
index 3992f9a0c..381faf91c 100644
--- a/src/device.c
+++ b/src/device.c
@@ -5545,7 +5545,7 @@ static void gatt_client_service_changed(uint16_t start_handle,
 
 static void gatt_debug(const char *str, void *user_data)
 {
-	DBG("%s", str);
+	DBG_IDX(0xffff, "%s", str);
 }
 
 static void gatt_client_init(struct btd_device *device)
-- 
2.35.1

RE: [RFC,BlueZ] adapter: Introduce BTD_ADAPTER_DBG

[bluez.test.bot]

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

This is automated email and please do not reply to this email!

Dear submitter,

Thank you for submitting the patches to the linux bluetooth mailing list.
This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=625872

---Test result---

Test Summary:
CheckPatch                    FAIL      12.99 seconds
GitLint                       PASS      8.66 seconds
Prep - Setup ELL              PASS      40.22 seconds
Build - Prep                  PASS      0.68 seconds
Build - Configure             PASS      8.17 seconds
Build - Make                  PASS      1211.61 seconds
Make Check                    PASS      10.97 seconds
Make Check w/Valgrind         PASS      417.60 seconds
Make Distcheck                PASS      222.33 seconds
Build w/ext ELL - Configure   PASS      8.66 seconds
Build w/ext ELL - Make        PASS      1243.22 seconds
Incremental Build with patchesPASS      11501.91 seconds

Details
##############################
Test: CheckPatch - FAIL
Desc: Run checkpatch.pl script with rule in .checkpatch.conf
Output:
[RFC,BlueZ] adapter: Introduce BTD_ADAPTER_DBG
ERROR:SPACING: space prohibited before that ',' (ctx:WxW)
#99: FILE: src/adapter.h:28:
+							__func__ , ## arg)
 							         ^

ERROR:SPACING: space prohibited before that ',' (ctx:WxW)
#114: FILE: src/device.h:16:
+							__func__ , ## arg)
 							         ^

/github/workspace/src/12790172.patch total: 2 errors, 0 warnings, 20 lines checked

NOTE: For some of the reported defects, checkpatch may be able to
      mechanically convert to the typical style using --fix or --fix-inplace.

/github/workspace/src/12790172.patch has style problems, please review.

NOTE: Ignored message types: COMMIT_MESSAGE COMPLEX_MACRO CONST_STRUCT FILE_PATH_CHANGES MISSING_SIGN_OFF PREFER_PACKED SPDX_LICENSE_TAG SPLIT_STRING SSCANF_TO_KSTRTO

NOTE: If any of the errors are false positives, please report
      them to the maintainer, see CHECKPATCH in MAINTAINERS.

[BlueZ,v4,3/9] mgmt: Introduce mgmt_set_verbose
WARNING:REPEATED_WORD: Possible repeated word: 'the'
#83: 
the the likes hexdump of packets, by default it is disabled since in

/github/workspace/src/12790175.patch total: 0 errors, 1 warnings, 61 lines checked

NOTE: For some of the reported defects, checkpatch may be able to
      mechanically convert to the typical style using --fix or --fix-inplace.

/github/workspace/src/12790175.patch has style problems, please review.

NOTE: Ignored message types: COMMIT_MESSAGE COMPLEX_MACRO CONST_STRUCT FILE_PATH_CHANGES MISSING_SIGN_OFF PREFER_PACKED SPDX_LICENSE_TAG SPLIT_STRING SSCANF_TO_KSTRTO

NOTE: If any of the errors are false positives, please report
      them to the maintainer, see CHECKPATCH in MAINTAINERS.




---
Regards,
Linux Bluetooth

Re: [RFC BlueZ] adapter: Introduce BTD_ADAPTER_DBG

[patchwork-bot+bluetooth]

Hello:

This series was applied to bluetooth/bluez.git (master)
by Luiz Augusto von Dentz <luiz.von.dentz@intel.com>:

On Wed, 23 Mar 2022 15:39:54 -0700 you wrote:
> From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
> 
> This introduces BTD_ADAPTER_DBG which includes the controller index
> when using DBG_IDX, in addition to it also add similar macro for
> devices in the form of BTD_DEVICE_DBG which resolves the adapter and
> before calling BTD_ADAPTER_DBG.
> 
> [...]

Here is the summary with links:
  - [RFC,BlueZ] adapter: Introduce BTD_ADAPTER_DBG
    (no matching commit)
  - [BlueZ,v4,2/9] mgmt: Add DBG macro
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=f9cb7c802f27
  - [BlueZ,v4,3/9] mgmt: Introduce mgmt_set_verbose
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=b7c807269f1f
  - [BlueZ,v4,4/9] adapter: Don't use DBG in mgmt_debug
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=62c6037ea02b
  - [BlueZ,v4,5/9] att: Log file and function names
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=8039d42687fd
  - [BlueZ,v4,6/9] gatt-client: Add DBG macro
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=e0870ce5e1fe
  - [BlueZ,v4,7/9] gatt-server: Add DBG macro
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=55c25d91e4d6
  - [BlueZ,v4,8/9] att: Rename att_debug and att_verbose to DBG and VERBOSE
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=e1b808c128fa
  - [BlueZ,v4,9/9] device: Don't use DBG in gatt_debug
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=71cec503c8da

You are awesome, thank you!
-- 
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html