libertastf: add configurable debug messages

Add the same type of configurable debug messages to libertas_tf as
already exist in the libertas driver.  This has facilitated creation
of a interface specification and will facilitate future development
of this driver.

Signed-off-by: Steve deRosier <steve@cozybit.com>
Signed-off-by: John W. Linville <linville@tuxdriver.com>
diff --git a/drivers/net/wireless/libertas_tf/cmd.c b/drivers/net/wireless/libertas_tf/cmd.c
index 28790e0..22645e4 100644
--- a/drivers/net/wireless/libertas_tf/cmd.c
+++ b/drivers/net/wireless/libertas_tf/cmd.c
@@ -7,6 +7,7 @@
  *  the Free Software Foundation; either version 2 of the License, or (at
  *  your option) any later version.
  */
+#include "deb_defs.h"
 #include "libertas_tf.h"
 
 static const struct channel_range channel_ranges[] = {
@@ -80,6 +81,8 @@
 	int ret = -1;
 	u32 i;
 
+	lbtf_deb_enter(LBTF_DEB_CMD);
+
 	memset(&cmd, 0, sizeof(cmd));
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	memcpy(cmd.permanentaddr, priv->current_addr, ETH_ALEN);
@@ -102,6 +105,8 @@
 		priv->fwrelease >>  8 & 0xff,
 		priv->fwrelease       & 0xff,
 		priv->fwcapinfo);
+	lbtf_deb_cmd("GET_HW_SPEC: hardware interface 0x%x, hardware spec 0x%04x\n",
+		    cmd.hwifversion, cmd.version);
 
 	/* Clamp region code to 8-bit since FW spec indicates that it should
 	 * only ever be 8-bit, even though the field size is 16-bit.  Some
@@ -116,8 +121,10 @@
 	}
 
 	/* if it's unidentified region code, use the default (USA) */
-	if (i >= MRVDRV_MAX_REGION_CODE)
+	if (i >= MRVDRV_MAX_REGION_CODE) {
 		priv->regioncode = 0x10;
+		pr_info("unidentified region code; using the default (USA)\n");
+	}
 
 	if (priv->current_addr[0] == 0xff)
 		memmove(priv->current_addr, cmd.permanentaddr, ETH_ALEN);
@@ -126,6 +133,7 @@
 
 	lbtf_geo_init(priv);
 out:
+	lbtf_deb_leave(LBTF_DEB_CMD);
 	return ret;
 }
 
@@ -139,13 +147,18 @@
  */
 int lbtf_set_channel(struct lbtf_private *priv, u8 channel)
 {
+	int ret = 0;
 	struct cmd_ds_802_11_rf_channel cmd;
 
+	lbtf_deb_enter(LBTF_DEB_CMD);
+
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.action = cpu_to_le16(CMD_OPT_802_11_RF_CHANNEL_SET);
 	cmd.channel = cpu_to_le16(channel);
 
-	return lbtf_cmd_with_response(priv, CMD_802_11_RF_CHANNEL, &cmd);
+	ret = lbtf_cmd_with_response(priv, CMD_802_11_RF_CHANNEL, &cmd);
+	lbtf_deb_leave_args(LBTF_DEB_CMD, "ret %d", ret);
+	return ret;
 }
 
 int lbtf_beacon_set(struct lbtf_private *priv, struct sk_buff *beacon)
@@ -153,20 +166,28 @@
 	struct cmd_ds_802_11_beacon_set cmd;
 	int size;
 
-	if (beacon->len > MRVL_MAX_BCN_SIZE)
+	lbtf_deb_enter(LBTF_DEB_CMD);
+
+	if (beacon->len > MRVL_MAX_BCN_SIZE) {
+		lbtf_deb_leave_args(LBTF_DEB_CMD, "ret %d", -1);
 		return -1;
+	}
 	size =  sizeof(cmd) - sizeof(cmd.beacon) + beacon->len;
 	cmd.hdr.size = cpu_to_le16(size);
 	cmd.len = cpu_to_le16(beacon->len);
 	memcpy(cmd.beacon, (u8 *) beacon->data, beacon->len);
 
 	lbtf_cmd_async(priv, CMD_802_11_BEACON_SET, &cmd.hdr, size);
+
+	lbtf_deb_leave_args(LBTF_DEB_CMD, "ret %d", 0);
 	return 0;
 }
 
 int lbtf_beacon_ctrl(struct lbtf_private *priv, bool beacon_enable,
-		     int beacon_int) {
+		     int beacon_int)
+{
 	struct cmd_ds_802_11_beacon_control cmd;
+	lbtf_deb_enter(LBTF_DEB_CMD);
 
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.action = cpu_to_le16(CMD_ACT_SET);
@@ -174,6 +195,8 @@
 	cmd.beacon_period = cpu_to_le16(beacon_int);
 
 	lbtf_cmd_async(priv, CMD_802_11_BEACON_CTRL, &cmd.hdr, sizeof(cmd));
+
+	lbtf_deb_leave(LBTF_DEB_CMD);
 	return 0;
 }
 
@@ -181,17 +204,28 @@
 			  struct cmd_ctrl_node *cmdnode)
 {
 	unsigned long flags;
+	lbtf_deb_enter(LBTF_DEB_HOST);
 
-	if (!cmdnode)
-		return;
+	if (!cmdnode) {
+		lbtf_deb_host("QUEUE_CMD: cmdnode is NULL\n");
+		goto qcmd_done;
+	}
 
-	if (!cmdnode->cmdbuf->size)
-		return;
+	if (!cmdnode->cmdbuf->size) {
+		lbtf_deb_host("DNLD_CMD: cmd size is zero\n");
+		goto qcmd_done;
+	}
 
 	cmdnode->result = 0;
 	spin_lock_irqsave(&priv->driver_lock, flags);
 	list_add_tail(&cmdnode->list, &priv->cmdpendingq);
 	spin_unlock_irqrestore(&priv->driver_lock, flags);
+
+	lbtf_deb_host("QUEUE_CMD: inserted command 0x%04x into cmdpendingq\n",
+		     le16_to_cpu(cmdnode->cmdbuf->command));
+
+qcmd_done:
+	lbtf_deb_leave(LBTF_DEB_HOST);
 }
 
 static void lbtf_submit_command(struct lbtf_private *priv,
@@ -204,22 +238,33 @@
 	int timeo = 5 * HZ;
 	int ret;
 
+	lbtf_deb_enter(LBTF_DEB_HOST);
+
 	cmd = cmdnode->cmdbuf;
 
 	spin_lock_irqsave(&priv->driver_lock, flags);
 	priv->cur_cmd = cmdnode;
 	cmdsize = le16_to_cpu(cmd->size);
 	command = le16_to_cpu(cmd->command);
+
+	lbtf_deb_cmd("DNLD_CMD: command 0x%04x, seq %d, size %d\n",
+		     command, le16_to_cpu(cmd->seqnum), cmdsize);
+	lbtf_deb_hex(LBTF_DEB_CMD, "DNLD_CMD", (void *) cmdnode->cmdbuf, cmdsize);
+
 	ret = priv->hw_host_to_card(priv, MVMS_CMD, (u8 *) cmd, cmdsize);
 	spin_unlock_irqrestore(&priv->driver_lock, flags);
 
-	if (ret)
+	if (ret) {
+		pr_info("DNLD_CMD: hw_host_to_card failed: %d\n", ret);
 		/* Let the timer kick in and retry, and potentially reset
 		   the whole thing if the condition persists */
 		timeo = HZ;
+	}
 
 	/* Setup the timer after transmit command */
 	mod_timer(&priv->command_timer, jiffies + timeo);
+
+	lbtf_deb_leave(LBTF_DEB_HOST);
 }
 
 /**
@@ -229,8 +274,10 @@
 static void __lbtf_cleanup_and_insert_cmd(struct lbtf_private *priv,
 					 struct cmd_ctrl_node *cmdnode)
 {
+	lbtf_deb_enter(LBTF_DEB_HOST);
+
 	if (!cmdnode)
-		return;
+		goto cl_ins_out;
 
 	cmdnode->callback = NULL;
 	cmdnode->callback_arg = 0;
@@ -238,6 +285,9 @@
 	memset(cmdnode->cmdbuf, 0, LBS_CMD_BUFFER_SIZE);
 
 	list_add_tail(&cmdnode->list, &priv->cmdfreeq);
+
+cl_ins_out:
+	lbtf_deb_leave(LBTF_DEB_HOST);
 }
 
 static void lbtf_cleanup_and_insert_cmd(struct lbtf_private *priv,
@@ -266,29 +316,41 @@
 {
 	struct cmd_ds_mac_multicast_addr cmd;
 
+	lbtf_deb_enter(LBTF_DEB_CMD);
+
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.action = cpu_to_le16(CMD_ACT_SET);
 
 	cmd.nr_of_adrs = cpu_to_le16((u16) priv->nr_of_multicastmacaddr);
+
+	lbtf_deb_cmd("MULTICAST_ADR: setting %d addresses\n", cmd.nr_of_adrs);
+
 	memcpy(cmd.maclist, priv->multicastlist,
 	       priv->nr_of_multicastmacaddr * ETH_ALEN);
 
 	lbtf_cmd_async(priv, CMD_MAC_MULTICAST_ADR, &cmd.hdr, sizeof(cmd));
+
+	lbtf_deb_leave(LBTF_DEB_CMD);
 	return 0;
 }
 
 void lbtf_set_mode(struct lbtf_private *priv, enum lbtf_mode mode)
 {
 	struct cmd_ds_set_mode cmd;
+	lbtf_deb_enter(LBTF_DEB_WEXT);
 
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.mode = cpu_to_le16(mode);
+	lbtf_deb_wext("Switching to mode: 0x%x\n", mode);
 	lbtf_cmd_async(priv, CMD_802_11_SET_MODE, &cmd.hdr, sizeof(cmd));
+
+	lbtf_deb_leave(LBTF_DEB_WEXT);
 }
 
 void lbtf_set_bssid(struct lbtf_private *priv, bool activate, const u8 *bssid)
 {
 	struct cmd_ds_set_bssid cmd;
+	lbtf_deb_enter(LBTF_DEB_CMD);
 
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.activate = activate ? 1 : 0;
@@ -296,11 +358,13 @@
 		memcpy(cmd.bssid, bssid, ETH_ALEN);
 
 	lbtf_cmd_async(priv, CMD_802_11_SET_BSSID, &cmd.hdr, sizeof(cmd));
+	lbtf_deb_leave(LBTF_DEB_CMD);
 }
 
 int lbtf_set_mac_address(struct lbtf_private *priv, uint8_t *mac_addr)
 {
 	struct cmd_ds_802_11_mac_address cmd;
+	lbtf_deb_enter(LBTF_DEB_CMD);
 
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.action = cpu_to_le16(CMD_ACT_SET);
@@ -308,6 +372,7 @@
 	memcpy(cmd.macadd, mac_addr, ETH_ALEN);
 
 	lbtf_cmd_async(priv, CMD_802_11_MAC_ADDRESS, &cmd.hdr, sizeof(cmd));
+	lbtf_deb_leave(LBTF_DEB_CMD);
 	return 0;
 }
 
@@ -316,6 +381,8 @@
 	int ret = 0;
 	struct cmd_ds_802_11_radio_control cmd;
 
+	lbtf_deb_enter(LBTF_DEB_CMD);
+
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.action = cpu_to_le16(CMD_ACT_SET);
 
@@ -339,19 +406,28 @@
 	else
 		cmd.control &= cpu_to_le16(~TURN_ON_RF);
 
+	lbtf_deb_cmd("RADIO_SET: radio %d, preamble %d\n", priv->radioon,
+		    priv->preamble);
+
 	ret = lbtf_cmd_with_response(priv, CMD_802_11_RADIO_CONTROL, &cmd);
+
+	lbtf_deb_leave_args(LBTF_DEB_CMD, "ret %d", ret);
 	return ret;
 }
 
 void lbtf_set_mac_control(struct lbtf_private *priv)
 {
 	struct cmd_ds_mac_control cmd;
+	lbtf_deb_enter(LBTF_DEB_CMD);
+
 	cmd.hdr.size = cpu_to_le16(sizeof(cmd));
 	cmd.action = cpu_to_le16(priv->mac_control);
 	cmd.reserved = 0;
 
 	lbtf_cmd_async(priv, CMD_MAC_CONTROL,
 		&cmd.hdr, sizeof(cmd));
+
+	lbtf_deb_leave(LBTF_DEB_CMD);
 }
 
 /**
@@ -363,29 +439,43 @@
  */
 int lbtf_allocate_cmd_buffer(struct lbtf_private *priv)
 {
+	int ret = 0;
 	u32 bufsize;
 	u32 i;
 	struct cmd_ctrl_node *cmdarray;
 
+	lbtf_deb_enter(LBTF_DEB_HOST);
+
 	/* Allocate and initialize the command array */
 	bufsize = sizeof(struct cmd_ctrl_node) * LBS_NUM_CMD_BUFFERS;
 	cmdarray = kzalloc(bufsize, GFP_KERNEL);
-	if (!cmdarray)
-		return -1;
+	if (!cmdarray) {
+		lbtf_deb_host("ALLOC_CMD_BUF: tempcmd_array is NULL\n");
+		ret = -1;
+		goto done;
+	}
 	priv->cmd_array = cmdarray;
 
 	/* Allocate and initialize each command buffer in the command array */
 	for (i = 0; i < LBS_NUM_CMD_BUFFERS; i++) {
 		cmdarray[i].cmdbuf = kzalloc(LBS_CMD_BUFFER_SIZE, GFP_KERNEL);
-		if (!cmdarray[i].cmdbuf)
-			return -1;
+		if (!cmdarray[i].cmdbuf) {
+			lbtf_deb_host("ALLOC_CMD_BUF: ptempvirtualaddr is NULL\n");
+			ret = -1;
+			goto done;
+		}
 	}
 
 	for (i = 0; i < LBS_NUM_CMD_BUFFERS; i++) {
 		init_waitqueue_head(&cmdarray[i].cmdwait_q);
 		lbtf_cleanup_and_insert_cmd(priv, &cmdarray[i]);
 	}
-	return 0;
+
+	ret = 0;
+
+done:
+	lbtf_deb_leave_args(LBTF_DEB_HOST, "ret %d", ret);
+	return ret;
 }
 
 /**
@@ -400,9 +490,13 @@
 	struct cmd_ctrl_node *cmdarray;
 	unsigned int i;
 
+	lbtf_deb_enter(LBTF_DEB_HOST);
+
 	/* need to check if cmd array is allocated or not */
-	if (priv->cmd_array == NULL)
-		return 0;
+	if (priv->cmd_array == NULL) {
+		lbtf_deb_host("FREE_CMD_BUF: cmd_array is NULL\n");
+		goto done;
+	}
 
 	cmdarray = priv->cmd_array;
 
@@ -416,6 +510,8 @@
 	kfree(priv->cmd_array);
 	priv->cmd_array = NULL;
 
+done:
+	lbtf_deb_leave(LBTF_DEB_HOST);
 	return 0;
 }
 
@@ -431,6 +527,8 @@
 	struct cmd_ctrl_node *tempnode;
 	unsigned long flags;
 
+	lbtf_deb_enter(LBTF_DEB_HOST);
+
 	if (!priv)
 		return NULL;
 
@@ -440,11 +538,14 @@
 		tempnode = list_first_entry(&priv->cmdfreeq,
 					    struct cmd_ctrl_node, list);
 		list_del(&tempnode->list);
-	} else
+	} else {
+		lbtf_deb_host("GET_CMD_NODE: cmd_ctrl_node is not available\n");
 		tempnode = NULL;
+	}
 
 	spin_unlock_irqrestore(&priv->driver_lock, flags);
 
+	lbtf_deb_leave(LBTF_DEB_HOST);
 	return tempnode;
 }
 
@@ -460,16 +561,20 @@
 	struct cmd_ctrl_node *cmdnode = NULL;
 	struct cmd_header *cmd;
 	unsigned long flags;
+	int ret = 0;
 
-	/* Debug group is LBS_DEB_THREAD and not LBS_DEB_HOST, because the
+	/* Debug group is lbtf_deb_THREAD and not lbtf_deb_HOST, because the
 	 * only caller to us is lbtf_thread() and we get even when a
 	 * data packet is received */
+	lbtf_deb_enter(LBTF_DEB_THREAD);
 
 	spin_lock_irqsave(&priv->driver_lock, flags);
 
 	if (priv->cur_cmd) {
+		pr_alert("EXEC_NEXT_CMD: already processing command!\n");
 		spin_unlock_irqrestore(&priv->driver_lock, flags);
-		return -1;
+		ret = -1;
+		goto done;
 	}
 
 	if (!list_empty(&priv->cmdpendingq)) {
@@ -481,11 +586,17 @@
 		cmd = cmdnode->cmdbuf;
 
 		list_del(&cmdnode->list);
+		lbtf_deb_host("EXEC_NEXT_CMD: sending command 0x%04x\n",
+			    le16_to_cpu(cmd->command));
 		spin_unlock_irqrestore(&priv->driver_lock, flags);
 		lbtf_submit_command(priv, cmdnode);
 	} else
 		spin_unlock_irqrestore(&priv->driver_lock, flags);
-	return 0;
+
+	ret = 0;
+done:
+	lbtf_deb_leave(LBTF_DEB_THREAD);
+	return ret;
 }
 
 static struct cmd_ctrl_node *__lbtf_cmd_async(struct lbtf_private *priv,
@@ -496,14 +607,22 @@
 {
 	struct cmd_ctrl_node *cmdnode;
 
-	if (priv->surpriseremoved)
-		return ERR_PTR(-ENOENT);
+	lbtf_deb_enter(LBTF_DEB_HOST);
+
+	if (priv->surpriseremoved) {
+		lbtf_deb_host("PREP_CMD: card removed\n");
+		cmdnode = ERR_PTR(-ENOENT);
+		goto done;
+	}
 
 	cmdnode = lbtf_get_cmd_ctrl_node(priv);
 	if (cmdnode == NULL) {
+		lbtf_deb_host("PREP_CMD: cmdnode is NULL\n");
+
 		/* Wake up main thread to execute next command */
 		queue_work(lbtf_wq, &priv->cmd_work);
-		return ERR_PTR(-ENOBUFS);
+		cmdnode = ERR_PTR(-ENOBUFS);
+		goto done;
 	}
 
 	cmdnode->callback = callback;
@@ -518,17 +637,24 @@
 	cmdnode->cmdbuf->size    = cpu_to_le16(in_cmd_size);
 	cmdnode->cmdbuf->seqnum  = cpu_to_le16(priv->seqnum);
 	cmdnode->cmdbuf->result  = 0;
+
+	lbtf_deb_host("PREP_CMD: command 0x%04x\n", command);
+
 	cmdnode->cmdwaitqwoken = 0;
 	lbtf_queue_cmd(priv, cmdnode);
 	queue_work(lbtf_wq, &priv->cmd_work);
 
+ done:
+	lbtf_deb_leave_args(LBTF_DEB_HOST, "ret %p", cmdnode);
 	return cmdnode;
 }
 
 void lbtf_cmd_async(struct lbtf_private *priv, uint16_t command,
 	struct cmd_header *in_cmd, int in_cmd_size)
 {
+	lbtf_deb_enter(LBTF_DEB_CMD);
 	__lbtf_cmd_async(priv, command, in_cmd, in_cmd_size, NULL, 0);
+	lbtf_deb_leave(LBTF_DEB_CMD);
 }
 
 int __lbtf_cmd(struct lbtf_private *priv, uint16_t command,
@@ -541,30 +667,35 @@
 	unsigned long flags;
 	int ret = 0;
 
+	lbtf_deb_enter(LBTF_DEB_HOST);
+
 	cmdnode = __lbtf_cmd_async(priv, command, in_cmd, in_cmd_size,
 				  callback, callback_arg);
-	if (IS_ERR(cmdnode))
-		return PTR_ERR(cmdnode);
+	if (IS_ERR(cmdnode)) {
+		ret = PTR_ERR(cmdnode);
+		goto done;
+	}
 
 	might_sleep();
 	ret = wait_event_interruptible(cmdnode->cmdwait_q,
 				       cmdnode->cmdwaitqwoken);
-       if (ret)	{
-		printk(KERN_DEBUG
-		       "libertastf: command 0x%04x interrupted by signal",
-		       command);
-		return ret;
+	if (ret) {
+		pr_info("PREP_CMD: command 0x%04x interrupted by signal: %d\n",
+			    command, ret);
+		goto done;
 	}
 
 	spin_lock_irqsave(&priv->driver_lock, flags);
 	ret = cmdnode->result;
 	if (ret)
-		printk(KERN_DEBUG "libertastf: command 0x%04x failed: %d\n",
+		pr_info("PREP_CMD: command 0x%04x failed: %d\n",
 			    command, ret);
 
 	__lbtf_cleanup_and_insert_cmd(priv, cmdnode);
 	spin_unlock_irqrestore(&priv->driver_lock, flags);
 
+done:
+	lbtf_deb_leave_args(LBTF_DEB_HOST, "ret %d", ret);
 	return ret;
 }
 EXPORT_SYMBOL_GPL(__lbtf_cmd);
@@ -585,6 +716,8 @@
 	unsigned long flags;
 	uint16_t result;
 
+	lbtf_deb_enter(LBTF_DEB_CMD);
+
 	mutex_lock(&priv->lock);
 	spin_lock_irqsave(&priv->driver_lock, flags);
 
@@ -600,7 +733,7 @@
 	result = le16_to_cpu(resp->result);
 
 	if (net_ratelimit())
-		printk(KERN_DEBUG "libertastf: cmd response 0x%04x, seq %d, size %d\n",
+		pr_info("libertastf: cmd response 0x%04x, seq %d, size %d\n",
 			respcmd, le16_to_cpu(resp->seqnum),
 			le16_to_cpu(resp->size));
 
@@ -637,7 +770,7 @@
 		switch (respcmd) {
 		case CMD_RET(CMD_GET_HW_SPEC):
 		case CMD_RET(CMD_802_11_RESET):
-			printk(KERN_DEBUG "libertastf: reset failed\n");
+			pr_info("libertastf: reset failed\n");
 			break;
 
 		}
@@ -664,5 +797,6 @@
 
 done:
 	mutex_unlock(&priv->lock);
+	lbtf_deb_leave_args(LBTF_DEB_CMD, "ret %d", ret);
 	return ret;
 }