[PATCH BlueZ 2/4] shared/att: Add debug level to bt_att_set_debug

[Luiz Augusto von Dentz <luiz.dentz@gmail.com>]

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

This creates different levels of debugging which can be passed to
bt_att_set_debug as depending on the application it may not need to
print everything which can pollute the logs quite a bit.
---
 src/shared/att.c      | 108 +++++++++++++++++++++++-------------------
 src/shared/att.h      |   9 +++-
 tools/btgatt-client.c |   3 +-
 tools/btgatt-server.c |   3 +-
 unit/test-gatt.c      |   2 +-
 5 files changed, 71 insertions(+), 54 deletions(-)

diff --git a/src/shared/att.c b/src/shared/att.c
index 429ba6696..ccc753c4e 100644
--- a/src/shared/att.c
+++ b/src/shared/att.c
@@ -77,6 +77,7 @@ struct bt_att {
 	bt_att_destroy_func_t timeout_destroy;
 	void *timeout_data;
 
+	uint8_t debug_level;
 	bt_att_debug_func_t debug_callback;
 	bt_att_destroy_func_t debug_destroy;
 	void *debug_data;
@@ -274,6 +275,34 @@ static bool match_disconn_id(const void *a, const void *b)
 	return disconn->id == id;
 }
 
+static void att_log(struct bt_att *att, uint8_t level, const char *format,
+								...)
+{
+	va_list va;
+
+	if (att->debug_level < level)
+		return;
+
+	va_start(va, format);
+	util_debug_va(att->debug_callback, att->debug_data, format, va);
+	va_end(va);
+}
+
+#define att_debug(_att, _format, _arg...) \
+	att_log(_att, BT_ATT_DEBUG, _format, ## _arg)
+
+#define att_verbose(_att, _format, _arg...) \
+	att_log(_att, BT_ATT_DEBUG_VERBOSE, _format, ## _arg)
+
+static void att_hexdump(struct bt_att *att, char dir, const void *data,
+							size_t len)
+{
+	if (att->debug_level < 2)
+		return;
+
+	util_hexdump(dir, data, len, att->debug_callback, att->debug_data);
+}
+
 static bool encode_pdu(struct bt_att *att, struct att_send_op *op,
 					const void *pdu, uint16_t length)
 {
@@ -309,8 +338,7 @@ static bool encode_pdu(struct bt_att *att, struct att_send_op *op,
 				sign_cnt, &((uint8_t *) op->pdu)[1 + length])))
 		return true;
 
-	util_debug(att->debug_callback, att->debug_data,
-					"ATT unable to generate signature");
+	att_debug(att, "ATT unable to generate signature");
 
 fail:
 	free(op->pdu);
@@ -432,9 +460,8 @@ static bool timeout_cb(void *user_data)
 	if (!op)
 		return false;
 
-	util_debug(att->debug_callback, att->debug_data,
-				"(chan %p) Operation timed out: 0x%02x",
-				chan, op->opcode);
+	att_debug(att, "(chan %p) Operation timed out: 0x%02x", chan,
+						op->opcode);
 
 	if (att->timeout_callback)
 		att->timeout_callback(op->id, op->opcode, att->timeout_data);
@@ -469,20 +496,18 @@ static ssize_t bt_att_chan_write(struct bt_att_chan *chan, uint8_t opcode,
 	iov.iov_base = (void *) pdu;
 	iov.iov_len = len;
 
-	util_debug(att->debug_callback, att->debug_data,
-					"(chan %p) ATT op 0x%02x",
-					chan, opcode);
+	att_verbose(att, "(chan %p) ATT op 0x%02x", chan, opcode);
 
 	ret = io_send(chan->io, &iov, 1);
 	if (ret < 0) {
-		util_debug(att->debug_callback, att->debug_data,
-					"(chan %p) write failed: %s",
-					chan, strerror(-ret));
-
+		att_debug(att, "(chan %p) write failed: %s", chan,
+						strerror(-ret));
 		return ret;
 	}
 
-	util_hexdump('<', pdu, ret, att->debug_callback, att->debug_data);
+	if (att->debug_level)
+		util_hexdump('<', pdu, ret, att->debug_callback,
+						att->debug_data);
 
 	return ret;
 }
@@ -608,15 +633,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) {
-		util_debug(chan->att->debug_callback, chan->att->debug_data,
-					"(chan %p) Failed to obtain disconnect"
-					" error: %s", chan, strerror(errno));
+		att_debug(att, "(chan %p) Failed to obtain disconnect "
+				"error: %s", chan, strerror(errno));
 		err = 0;
 	}
 
-	util_debug(chan->att->debug_callback, chan->att->debug_data,
-					"Channel %p disconnected: %s",
-					chan, strerror(err));
+	att_debug(att, "Channel %p disconnected: %s", chan, strerror(err));
 
 	/* Dettach channel */
 	queue_remove(att->chans, chan);
@@ -745,9 +767,7 @@ static bool handle_error_rsp(struct bt_att_chan *chan, uint8_t *pdu,
 		op->timeout_id = 0;
 	}
 
-	util_debug(att->debug_callback, att->debug_data,
-						"(chan %p) Retrying operation "
-						"%p", chan, op);
+	att_debug(att, "(chan %p) Retrying operation %p", chan, op);
 
 	chan->pending_req = NULL;
 
@@ -770,9 +790,8 @@ static void handle_rsp(struct bt_att_chan *chan, uint8_t opcode, uint8_t *pdu,
 	 * the bearer.
 	 */
 	if (!op) {
-		util_debug(att->debug_callback, att->debug_data,
-					"(chan %p) Received unexpected ATT "
-					"response", chan);
+		att_debug(att, "(chan %p) Received unexpected ATT response",
+								chan);
 		io_shutdown(chan->io);
 		return;
 	}
@@ -803,8 +822,7 @@ static void handle_rsp(struct bt_att_chan *chan, uint8_t opcode, uint8_t *pdu,
 	goto done;
 
 fail:
-	util_debug(att->debug_callback, att->debug_data,
-			"(chan %p) Failed to handle response PDU; opcode: "
+	att_debug(att, "(chan %p) Failed to handle response PDU; opcode: "
 			"0x%02x", chan, opcode);
 
 	rsp_opcode = BT_ATT_OP_ERROR_RSP;
@@ -829,8 +847,7 @@ static void handle_conf(struct bt_att_chan *chan, uint8_t *pdu, ssize_t pdu_len)
 	 * invalid.
 	 */
 	if (!op || pdu_len) {
-		util_debug(att->debug_callback, att->debug_data,
-				"(chan %p) Received unexpected/invalid ATT "
+		att_debug(att, "(chan %p) Received unexpected/invalid ATT "
 				"confirmation", chan);
 		io_shutdown(chan->io);
 		return;
@@ -904,8 +921,7 @@ static bool handle_signed(struct bt_att *att, uint8_t *pdu, ssize_t pdu_len)
 	return true;
 
 fail:
-	util_debug(att->debug_callback, att->debug_data,
-			"ATT failed to verify signature: 0x%02x", opcode);
+	att_debug(att, "ATT failed to verify signature: 0x%02x", opcode);
 
 	return false;
 }
@@ -987,12 +1003,9 @@ static bool can_read_data(struct io *io, void *user_data)
 	if (bytes_read < 0)
 		return false;
 
-	util_debug(att->debug_callback, att->debug_data,
-				"(chan %p) ATT received: %zd",
-				chan, bytes_read);
+	att_verbose(att, "(chan %p) ATT received: %zd", chan, bytes_read);
 
-	util_hexdump('>', chan->buf, bytes_read,
-				att->debug_callback, att->debug_data);
+	att_hexdump(att, '>', chan->buf, bytes_read);
 
 	if (bytes_read < ATT_MIN_PDU_LEN)
 		return true;
@@ -1005,14 +1018,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:
-		util_debug(att->debug_callback, att->debug_data,
-				"(chan %p) ATT response received: 0x%02x",
+		att_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:
-		util_debug(att->debug_callback, att->debug_data,
-				"(chan %p) ATT confirmation received: 0x%02x",
+		att_verbose(att, "(chan %p) ATT confirmation received: 0x%02x",
 				chan, opcode);
 		handle_conf(chan, pdu + 1, bytes_read - 1);
 		break;
@@ -1023,8 +1034,7 @@ static bool can_read_data(struct io *io, void *user_data)
 		 * promptly notify the upper layer via disconnect handlers.
 		 */
 		if (chan->in_req) {
-			util_debug(att->debug_callback, att->debug_data,
-					"(chan %p) Received request while "
+			att_debug(att, "(chan %p) Received request while "
 					"another is pending: 0x%02x",
 					chan, opcode);
 			io_shutdown(chan->io);
@@ -1044,9 +1054,8 @@ 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.
 		 */
-		util_debug(att->debug_callback, att->debug_data,
-					"(chan %p) ATT PDU received: 0x%02x",
-					chan, opcode);
+		att_debug(att, "(chan %p) ATT PDU received: 0x%02x", chan,
+							opcode);
 		handle_notify(chan, pdu, bytes_read);
 		break;
 	}
@@ -1198,8 +1207,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);
 
-	util_debug(att->debug_callback, att->debug_data, "Channel %p attached",
-									chan);
+	att_debug(att, "Channel %p attached", chan);
 
 	wakeup_chan_writer(chan, NULL);
 }
@@ -1315,8 +1323,9 @@ int bt_att_get_channels(struct bt_att *att)
 	return queue_length(att->chans);
 }
 
-bool bt_att_set_debug(struct bt_att *att, bt_att_debug_func_t callback,
-				void *user_data, bt_att_destroy_func_t destroy)
+bool bt_att_set_debug(struct bt_att *att, uint8_t level,
+			bt_att_debug_func_t callback, void *user_data,
+			bt_att_destroy_func_t destroy)
 {
 	if (!att)
 		return false;
@@ -1324,6 +1333,7 @@ bool bt_att_set_debug(struct bt_att *att, bt_att_debug_func_t callback,
 	if (att->debug_destroy)
 		att->debug_destroy(att->debug_data);
 
+	att->debug_level = level;
 	att->debug_callback = callback;
 	att->debug_destroy = destroy;
 	att->debug_data = user_data;
diff --git a/src/shared/att.h b/src/shared/att.h
index 1938fc724..03a450988 100644
--- a/src/shared/att.h
+++ b/src/shared/att.h
@@ -13,6 +13,10 @@
 
 #include "src/shared/att-types.h"
 
+#define BT_ATT_DEBUG		0x00
+#define BT_ATT_DEBUG_VERBOSE	0x01
+#define BT_ATT_DEBUG_HEXDUMP	0x02
+
 struct bt_att;
 struct bt_att_chan;
 
@@ -41,8 +45,9 @@ typedef void (*bt_att_timeout_func_t)(unsigned int id, uint8_t opcode,
 typedef void (*bt_att_disconnect_func_t)(int err, void *user_data);
 typedef bool (*bt_att_counter_func_t)(uint32_t *sign_cnt, void *user_data);
 
-bool bt_att_set_debug(struct bt_att *att, bt_att_debug_func_t callback,
-				void *user_data, bt_att_destroy_func_t destroy);
+bool bt_att_set_debug(struct bt_att *att, uint8_t level,
+			bt_att_debug_func_t callback, void *user_data,
+			bt_att_destroy_func_t destroy);
 
 uint16_t bt_att_get_mtu(struct bt_att *att);
 bool bt_att_set_mtu(struct bt_att *att, uint16_t mtu);
diff --git a/tools/btgatt-client.c b/tools/btgatt-client.c
index 523d6ec30..8c9365aa2 100644
--- a/tools/btgatt-client.c
+++ b/tools/btgatt-client.c
@@ -218,7 +218,8 @@ static struct client *client_create(int fd, uint16_t mtu)
 								NULL, NULL);
 
 	if (verbose) {
-		bt_att_set_debug(cli->att, att_debug_cb, "att: ", NULL);
+		bt_att_set_debug(cli->att, BT_ATT_DEBUG_VERBOSE, att_debug_cb,
+								"att: ", NULL);
 		bt_gatt_client_set_debug(cli->gatt, gatt_debug_cb, "gatt: ",
 									NULL);
 	}
diff --git a/tools/btgatt-server.c b/tools/btgatt-server.c
index aa3448765..000145a3d 100644
--- a/tools/btgatt-server.c
+++ b/tools/btgatt-server.c
@@ -584,7 +584,8 @@ static struct server *server_create(int fd, uint16_t mtu, bool hr_visible)
 	server->hr_visible = hr_visible;
 
 	if (verbose) {
-		bt_att_set_debug(server->att, att_debug_cb, "att: ", NULL);
+		bt_att_set_debug(server->att, BT_ATT_DEBUG_VERBOSE,
+						att_debug_cb, "att: ", NULL);
 		bt_gatt_server_set_debug(server->gatt, gatt_debug_cb,
 							"server: ", NULL);
 	}
diff --git a/unit/test-gatt.c b/unit/test-gatt.c
index 6a49210c5..4aa87d09c 100644
--- a/unit/test-gatt.c
+++ b/unit/test-gatt.c
@@ -658,7 +658,7 @@ static struct context *create_context(uint16_t mtu, gconstpointer data)
 
 	switch (test_data->context_type) {
 	case ATT:
-		bt_att_set_debug(context->att, print_debug, "bt_att:", NULL);
+		bt_att_set_debug(context->att, 1, print_debug, "bt_att:", NULL);
 
 		bt_gatt_exchange_mtu(context->att, mtu, NULL, NULL, NULL);
 		break;
-- 
2.26.2