s390/zcrypt: introduce dynamic debugging for AP and zcrypt code

This patch replaces all the s390 debug feature calls with
debug level by dynamic debug calls pr_debug. These calls
are much more flexible and each single invocation can get
enabled/disabled at runtime wheres the s390 debug feature
debug calls have only one knob - enable or disable all in
one bunch. The benefit is especially significant with
high frequency called functions like the AP bus scan. In
most debugging scenarios you don't want and need them, but
sometimes it is crucial to know exactly when and how long
the AP bus scan took.
Signed-off-by: Harald Freudenberger <freude@linux.ibm.com>
Reviewed-by: Holger Dengler <dengler@linux.ibm.com>
Signed-off-by: Heiko Carstens <hca@linux.ibm.com>

drivers/s390/crypto/ap_bus.c

@@ -826,8 +826,8 @@ static int __ap_revise_reserved(struct device *dev, void *dummy)
 		drvres = to_ap_drv(dev->driver)->flags
 			& AP_DRIVER_FLAG_DEFAULT;
 		if (!!devres != !!drvres) {
-			AP_DBF_DBG("%s reprobing queue=%02x.%04x\n",
-				   __func__, card, queue);
+			pr_debug("%s reprobing queue=%02x.%04x\n",
+				 __func__, card, queue);
 			rc = device_reprobe(dev);
 			if (rc)
 				AP_DBF_WARN("%s reprobing queue=%02x.%04x failed\n",
@@ -1030,7 +1030,7 @@ EXPORT_SYMBOL(ap_bus_force_rescan);
  */
 void ap_bus_cfg_chg(void)
 {
-	AP_DBF_DBG("%s config change, forcing bus rescan\n", __func__);
+	pr_debug("%s config change, forcing bus rescan\n", __func__);
 
 	ap_bus_force_rescan();
 }
@@ -1888,8 +1888,8 @@ static inline void ap_scan_domains(struct ap_card *ac)
 				aq->last_err_rc = AP_RESPONSE_CHECKSTOPPED;
 			}
 			spin_unlock_bh(&aq->lock);
-			AP_DBF_DBG("%s(%d,%d) queue dev checkstop on\n",
-				   __func__, ac->id, dom);
+			pr_debug("%s(%d,%d) queue dev checkstop on\n",
+				 __func__, ac->id, dom);
 			/* 'receive' pending messages with -EAGAIN */
 			ap_flush_queue(aq);
 			goto put_dev_and_continue;
@@ -1899,8 +1899,8 @@ static inline void ap_scan_domains(struct ap_card *ac)
 			if (aq->dev_state > AP_DEV_STATE_UNINITIATED)
 				_ap_queue_init_state(aq);
 			spin_unlock_bh(&aq->lock);
-			AP_DBF_DBG("%s(%d,%d) queue dev checkstop off\n",
-				   __func__, ac->id, dom);
+			pr_debug("%s(%d,%d) queue dev checkstop off\n",
+				 __func__, ac->id, dom);
 			goto put_dev_and_continue;
 		}
 		/* config state change */
@@ -1912,8 +1912,8 @@ static inline void ap_scan_domains(struct ap_card *ac)
 				aq->last_err_rc = AP_RESPONSE_DECONFIGURED;
 			}
 			spin_unlock_bh(&aq->lock);
-			AP_DBF_DBG("%s(%d,%d) queue dev config off\n",
-				   __func__, ac->id, dom);
+			pr_debug("%s(%d,%d) queue dev config off\n",
+				 __func__, ac->id, dom);
 			ap_send_config_uevent(&aq->ap_dev, aq->config);
 			/* 'receive' pending messages with -EAGAIN */
 			ap_flush_queue(aq);
@@ -1924,8 +1924,8 @@ static inline void ap_scan_domains(struct ap_card *ac)
 			if (aq->dev_state > AP_DEV_STATE_UNINITIATED)
 				_ap_queue_init_state(aq);
 			spin_unlock_bh(&aq->lock);
-			AP_DBF_DBG("%s(%d,%d) queue dev config on\n",
-				   __func__, ac->id, dom);
+			pr_debug("%s(%d,%d) queue dev config on\n",
+				 __func__, ac->id, dom);
 			ap_send_config_uevent(&aq->ap_dev, aq->config);
 			goto put_dev_and_continue;
 		}
@@ -1997,8 +1997,8 @@ static inline void ap_scan_adapter(int ap)
 			ap_scan_rm_card_dev_and_queue_devs(ac);
 			put_device(dev);
 		} else {
-			AP_DBF_DBG("%s(%d) no type info (no APQN found), ignored\n",
-				   __func__, ap);
+			pr_debug("%s(%d) no type info (no APQN found), ignored\n",
+				 __func__, ap);
 		}
 		return;
 	}
@@ -2010,8 +2010,8 @@ static inline void ap_scan_adapter(int ap)
 			ap_scan_rm_card_dev_and_queue_devs(ac);
 			put_device(dev);
 		} else {
-			AP_DBF_DBG("%s(%d) no valid type (0) info, ignored\n",
-				   __func__, ap);
+			pr_debug("%s(%d) no valid type (0) info, ignored\n",
+				 __func__, ap);
 		}
 		return;
 	}
@@ -2144,14 +2144,14 @@ static void ap_scan_bus(struct work_struct *unused)
 {
 	int ap, config_changed = 0;
 
+	pr_debug(">%s\n", __func__);
+
 	/* config change notify */
 	config_changed = ap_get_configuration();
 	if (config_changed)
 		notify_config_changed();
 	ap_select_domain();
 
-	AP_DBF_DBG("%s running\n", __func__);
-
 	/* loop over all possible adapters */
 	for (ap = 0; ap <= ap_max_adapter_id; ap++)
 		ap_scan_adapter(ap);
@@ -2174,12 +2174,14 @@ static void ap_scan_bus(struct work_struct *unused)
 	}
 
 	if (atomic64_inc_return(&ap_scan_bus_count) == 1) {
-		AP_DBF_DBG("%s init scan complete\n", __func__);
+		pr_debug("%s init scan complete\n", __func__);
 		ap_send_init_scan_done_uevent();
 		ap_check_bindings_complete();
 	}
 
 	mod_timer(&ap_config_timer, jiffies + ap_config_time * HZ);
+
+	pr_debug("<%s\n", __func__);
 }
 
 static void ap_config_timeout(struct timer_list *unused)

drivers/s390/crypto/ap_debug.h

@@ -26,8 +26,6 @@
 	debug_sprintf_event(ap_dbf_info, DBF_WARN, ##__VA_ARGS__)
 #define AP_DBF_INFO(...)					\
 	debug_sprintf_event(ap_dbf_info, DBF_INFO, ##__VA_ARGS__)
-#define AP_DBF_DBG(...)					\
-	debug_sprintf_event(ap_dbf_info, DBF_DEBUG, ##__VA_ARGS__)
 
 extern debug_info_t *ap_dbf_info;
 

drivers/s390/crypto/ap_queue.c

@@ -169,6 +169,9 @@ static struct ap_queue_status ap_sm_recv(struct ap_queue *aq)
 		aq->queue_count = 0;
 		list_splice_init(&aq->pendingq, &aq->requestq);
 		aq->requestq_count += aq->pendingq_count;
+		pr_debug("%s queue 0x%02x.%04x rescheduled %d reqs (new req %d)\n",
+			 __func__, AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid),
+			 aq->pendingq_count, aq->requestq_count);
 		aq->pendingq_count = 0;
 		break;
 	default:
@@ -446,9 +449,9 @@ static enum ap_sm_wait ap_sm_assoc_wait(struct ap_queue *aq)
 	case AP_BS_Q_USABLE:
 		/* association is through */
 		aq->sm_state = AP_SM_STATE_IDLE;
-		AP_DBF_DBG("%s queue 0x%02x.%04x associated with %u\n",
-			   __func__, AP_QID_CARD(aq->qid),
-			   AP_QID_QUEUE(aq->qid), aq->assoc_idx);
+		pr_debug("%s queue 0x%02x.%04x associated with %u\n",
+			 __func__, AP_QID_CARD(aq->qid),
+			 AP_QID_QUEUE(aq->qid), aq->assoc_idx);
 		return AP_SM_WAIT_NONE;
 	case AP_BS_Q_USABLE_NO_SECURE_KEY:
 		/* association still pending */
@@ -690,9 +693,9 @@ static ssize_t ap_functions_show(struct device *dev,
 
 	status = ap_test_queue(aq->qid, 1, &hwinfo);
 	if (status.response_code > AP_RESPONSE_BUSY) {
-		AP_DBF_DBG("%s RC 0x%02x on tapq(0x%02x.%04x)\n",
-			   __func__, status.response_code,
-			   AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid));
+		pr_debug("%s RC 0x%02x on tapq(0x%02x.%04x)\n",
+			 __func__, status.response_code,
+			 AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid));
 		return -EIO;
 	}
 
@@ -846,9 +849,9 @@ static ssize_t se_bind_show(struct device *dev,
 
 	status = ap_test_queue(aq->qid, 1, &hwinfo);
 	if (status.response_code > AP_RESPONSE_BUSY) {
-		AP_DBF_DBG("%s RC 0x%02x on tapq(0x%02x.%04x)\n",
-			   __func__, status.response_code,
-			   AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid));
+		pr_debug("%s RC 0x%02x on tapq(0x%02x.%04x)\n",
+			 __func__, status.response_code,
+			 AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid));
 		return -EIO;
 	}
 
@@ -974,9 +977,9 @@ static ssize_t se_associate_show(struct device *dev,
 
 	status = ap_test_queue(aq->qid, 1, &hwinfo);
 	if (status.response_code > AP_RESPONSE_BUSY) {
-		AP_DBF_DBG("%s RC 0x%02x on tapq(0x%02x.%04x)\n",
-			   __func__, status.response_code,
-			   AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid));
+		pr_debug("%s RC 0x%02x on tapq(0x%02x.%04x)\n",
+			 __func__, status.response_code,
+			 AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid));
 		return -EIO;
 	}
 

drivers/s390/crypto/zcrypt_api.c

@@ -12,6 +12,9 @@
  *  Multiple device nodes: Harald Freudenberger <freude@linux.ibm.com>
  */
 
+#define KMSG_COMPONENT "zcrypt"
+#define pr_fmt(fmt) KMSG_COMPONENT ": " fmt
+
 #include <linux/module.h>
 #include <linux/init.h>
 #include <linux/interrupt.h>
@@ -715,8 +718,7 @@ static long zcrypt_rsa_modexpo(struct ap_perms *perms,
 	spin_unlock(&zcrypt_list_lock);
 
 	if (!pref_zq) {
-		ZCRYPT_DBF_DBG("%s no matching queue found => ENODEV\n",
-			       __func__);
+		pr_debug("%s no matching queue found => ENODEV\n", __func__);
 		rc = -ENODEV;
 		goto out;
 	}
@@ -820,8 +822,7 @@ static long zcrypt_rsa_crt(struct ap_perms *perms,
 	spin_unlock(&zcrypt_list_lock);
 
 	if (!pref_zq) {
-		ZCRYPT_DBF_DBG("%s no matching queue found => ENODEV\n",
-			       __func__);
+		pr_debug("%s no matching queue found => ENODEV\n", __func__);
 		rc = -ENODEV;
 		goto out;
 	}
@@ -940,8 +941,8 @@ static long _zcrypt_send_cprb(bool userspace, struct ap_perms *perms,
 	spin_unlock(&zcrypt_list_lock);
 
 	if (!pref_zq) {
-		ZCRYPT_DBF_DBG("%s no match for address %02x.%04x => ENODEV\n",
-			       __func__, xcrb->user_defined, *domain);
+		pr_debug("%s no match for address %02x.%04x => ENODEV\n",
+			 __func__, xcrb->user_defined, *domain);
 		rc = -ENODEV;
 		goto out;
 	}
@@ -1113,15 +1114,15 @@ static long _zcrypt_send_ep11_cprb(bool userspace, struct ap_perms *perms,
 
 	if (!pref_zq) {
 		if (targets && target_num == 1) {
-			ZCRYPT_DBF_DBG("%s no match for address %02x.%04x => ENODEV\n",
-				       __func__, (int)targets->ap_id,
-				       (int)targets->dom_id);
+			pr_debug("%s no match for address %02x.%04x => ENODEV\n",
+				 __func__, (int)targets->ap_id,
+				 (int)targets->dom_id);
 		} else if (targets) {
-			ZCRYPT_DBF_DBG("%s no match for %d target addrs => ENODEV\n",
-				       __func__, (int)target_num);
+			pr_debug("%s no match for %d target addrs => ENODEV\n",
+				 __func__, (int)target_num);
 		} else {
-			ZCRYPT_DBF_DBG("%s no match for address ff.ffff => ENODEV\n",
-				       __func__);
+			pr_debug("%s no match for address ff.ffff => ENODEV\n",
+				 __func__);
 		}
 		rc = -ENODEV;
 		goto out_free;
@@ -1199,8 +1200,7 @@ static long zcrypt_rng(char *buffer)
 	spin_unlock(&zcrypt_list_lock);
 
 	if (!pref_zq) {
-		ZCRYPT_DBF_DBG("%s no matching queue found => ENODEV\n",
-			       __func__);
+		pr_debug("%s no matching queue found => ENODEV\n", __func__);
 		rc = -ENODEV;
 		goto out;
 	}
@@ -1444,7 +1444,7 @@ static int icarsamodexpo_ioctl(struct ap_perms *perms, unsigned long arg)
 	if (rc == -EAGAIN && tr.again_counter >= TRACK_AGAIN_MAX)
 		rc = -EIO;
 	if (rc) {
-		ZCRYPT_DBF_DBG("ioctl ICARSAMODEXPO rc=%d\n", rc);
+		pr_debug("ioctl ICARSAMODEXPO rc=%d\n", rc);
 		return rc;
 	}
 	return put_user(mex.outputdatalength, &umex->outputdatalength);
@@ -1476,7 +1476,7 @@ static int icarsacrt_ioctl(struct ap_perms *perms, unsigned long arg)
 	if (rc == -EAGAIN && tr.again_counter >= TRACK_AGAIN_MAX)
 		rc = -EIO;
 	if (rc) {
-		ZCRYPT_DBF_DBG("ioctl ICARSACRT rc=%d\n", rc);
+		pr_debug("ioctl ICARSACRT rc=%d\n", rc);
 		return rc;
 	}
 	return put_user(crt.outputdatalength, &ucrt->outputdatalength);
@@ -1508,8 +1508,8 @@ static int zsecsendcprb_ioctl(struct ap_perms *perms, unsigned long arg)
 	if (rc == -EAGAIN && tr.again_counter >= TRACK_AGAIN_MAX)
 		rc = -EIO;
 	if (rc)
-		ZCRYPT_DBF_DBG("ioctl ZSENDCPRB rc=%d status=0x%x\n",
-			       rc, xcrb.status);
+		pr_debug("ioctl ZSENDCPRB rc=%d status=0x%x\n",
+			 rc, xcrb.status);
 	if (copy_to_user(uxcrb, &xcrb, sizeof(xcrb)))
 		return -EFAULT;
 	return rc;
@@ -1541,7 +1541,7 @@ static int zsendep11cprb_ioctl(struct ap_perms *perms, unsigned long arg)
 	if (rc == -EAGAIN && tr.again_counter >= TRACK_AGAIN_MAX)
 		rc = -EIO;
 	if (rc)
-		ZCRYPT_DBF_DBG("ioctl ZSENDEP11CPRB rc=%d\n", rc);
+		pr_debug("ioctl ZSENDEP11CPRB rc=%d\n", rc);
 	if (copy_to_user(uxcrb, &xcrb, sizeof(xcrb)))
 		return -EFAULT;
 	return rc;
@@ -1670,7 +1670,7 @@ static long zcrypt_unlocked_ioctl(struct file *filp, unsigned int cmd,
 	}
 	/* unknown ioctl number */
 	default:
-		ZCRYPT_DBF_DBG("unknown ioctl 0x%08x\n", cmd);
+		pr_debug("unknown ioctl 0x%08x\n", cmd);
 		return -ENOIOCTLCMD;
 	}
 }
@@ -2014,8 +2014,8 @@ int zcrypt_wait_api_operational(void)
 			break;
 		default:
 			/* other failure */
-			ZCRYPT_DBF_DBG("%s ap_wait_init_apqn_bindings_complete()=%d\n",
-				       __func__, rc);
+			pr_debug("%s ap_wait_init_apqn_bindings_complete()=%d\n",
+				 __func__, rc);
 			break;
 		}
 		break;

drivers/s390/crypto/zcrypt_debug.h

@@ -27,8 +27,6 @@
 	debug_sprintf_event(zcrypt_dbf_info, DBF_WARN, ##__VA_ARGS__)
 #define ZCRYPT_DBF_INFO(...)					\
 	debug_sprintf_event(zcrypt_dbf_info, DBF_INFO, ##__VA_ARGS__)
-#define ZCRYPT_DBF_DBG(...)					\
-	debug_sprintf_event(zcrypt_dbf_info, DBF_DEBUG, ##__VA_ARGS__)
 
 extern debug_info_t *zcrypt_dbf_info;
 

drivers/s390/crypto/zcrypt_msgtype50.c

@@ -427,7 +427,7 @@ static void zcrypt_msgtype50_receive(struct ap_queue *aq,
 		len = t80h->len;
 		if (len > reply->bufsize || len > msg->bufsize ||
 		    len != reply->len) {
-			ZCRYPT_DBF_DBG("%s len mismatch => EMSGSIZE\n", __func__);
+			pr_debug("%s len mismatch => EMSGSIZE\n", __func__);
 			msg->rc = -EMSGSIZE;
 			goto out;
 		}
@@ -487,9 +487,9 @@ static long zcrypt_msgtype50_modexpo(struct zcrypt_queue *zq,
 out:
 	ap_msg->private = NULL;
 	if (rc)
-		ZCRYPT_DBF_DBG("%s send me cprb at dev=%02x.%04x rc=%d\n",
-			       __func__, AP_QID_CARD(zq->queue->qid),
-			       AP_QID_QUEUE(zq->queue->qid), rc);
+		pr_debug("%s send me cprb at dev=%02x.%04x rc=%d\n",
+			 __func__, AP_QID_CARD(zq->queue->qid),
+			 AP_QID_QUEUE(zq->queue->qid), rc);
 	return rc;
 }
 
@@ -537,9 +537,9 @@ static long zcrypt_msgtype50_modexpo_crt(struct zcrypt_queue *zq,
 out:
 	ap_msg->private = NULL;
 	if (rc)
-		ZCRYPT_DBF_DBG("%s send crt cprb at dev=%02x.%04x rc=%d\n",
-			       __func__, AP_QID_CARD(zq->queue->qid),
-			       AP_QID_QUEUE(zq->queue->qid), rc);
+		pr_debug("%s send crt cprb at dev=%02x.%04x rc=%d\n",
+			 __func__, AP_QID_CARD(zq->queue->qid),
+			 AP_QID_QUEUE(zq->queue->qid), rc);
 	return rc;
 }
 

drivers/s390/crypto/zcrypt_msgtype6.c

@@ -437,9 +437,9 @@ static int xcrb_msg_to_type6cprb_msgx(bool userspace, struct ap_message *ap_msg,
 		ap_msg->flags |= AP_MSG_FLAG_ADMIN;
 		break;
 	default:
-		ZCRYPT_DBF_DBG("%s unknown CPRB minor version '%c%c'\n",
-			       __func__, msg->cprbx.func_id[0],
-			       msg->cprbx.func_id[1]);
+		pr_debug("%s unknown CPRB minor version '%c%c'\n",
+			 __func__, msg->cprbx.func_id[0],
+			 msg->cprbx.func_id[1]);
 	}
 
 	/* copy data block */
@@ -629,9 +629,9 @@ static int convert_type86_xcrb(bool userspace, struct zcrypt_queue *zq,
 
 	/* Copy CPRB to user */
 	if (xcrb->reply_control_blk_length < msg->fmt2.count1) {
-		ZCRYPT_DBF_DBG("%s reply_control_blk_length %u < required %u => EMSGSIZE\n",
-			       __func__, xcrb->reply_control_blk_length,
-			       msg->fmt2.count1);
+		pr_debug("%s reply_control_blk_length %u < required %u => EMSGSIZE\n",
+			 __func__, xcrb->reply_control_blk_length,
+			 msg->fmt2.count1);
 		return -EMSGSIZE;
 	}
 	if (z_copy_to_user(userspace, xcrb->reply_control_blk_addr,
@@ -642,9 +642,9 @@ static int convert_type86_xcrb(bool userspace, struct zcrypt_queue *zq,
 	/* Copy data buffer to user */
 	if (msg->fmt2.count2) {
 		if (xcrb->reply_data_length < msg->fmt2.count2) {
-			ZCRYPT_DBF_DBG("%s reply_data_length %u < required %u => EMSGSIZE\n",
-				       __func__, xcrb->reply_data_length,
-				       msg->fmt2.count2);
+			pr_debug("%s reply_data_length %u < required %u => EMSGSIZE\n",
+				 __func__, xcrb->reply_data_length,
+				 msg->fmt2.count2);
 			return -EMSGSIZE;
 		}
 		if (z_copy_to_user(userspace, xcrb->reply_data_addr,
@@ -673,9 +673,9 @@ static int convert_type86_ep11_xcrb(bool userspace, struct zcrypt_queue *zq,
 	char *data = reply->msg;
 
 	if (xcrb->resp_len < msg->fmt2.count1) {
-		ZCRYPT_DBF_DBG("%s resp_len %u < required %u => EMSGSIZE\n",
-			       __func__, (unsigned int)xcrb->resp_len,
-			       msg->fmt2.count1);
+		pr_debug("%s resp_len %u < required %u => EMSGSIZE\n",
+			 __func__, (unsigned int)xcrb->resp_len,
+			 msg->fmt2.count1);
 		return -EMSGSIZE;
 	}
 
@@ -875,7 +875,8 @@ static void zcrypt_msgtype6_receive(struct ap_queue *aq,
 			len = sizeof(struct type86x_reply) + t86r->length;
 			if (len > reply->bufsize || len > msg->bufsize ||
 			    len != reply->len) {
-				ZCRYPT_DBF_DBG("%s len mismatch => EMSGSIZE\n", __func__);
+				pr_debug("%s len mismatch => EMSGSIZE\n",
+					 __func__);
 				msg->rc = -EMSGSIZE;
 				goto out;
 			}
@@ -889,7 +890,8 @@ static void zcrypt_msgtype6_receive(struct ap_queue *aq,
 				len = t86r->fmt2.offset1 + t86r->fmt2.count1;
 			if (len > reply->bufsize || len > msg->bufsize ||
 			    len != reply->len) {
-				ZCRYPT_DBF_DBG("%s len mismatch => EMSGSIZE\n", __func__);
+				pr_debug("%s len mismatch => EMSGSIZE\n",
+					 __func__);
 				msg->rc = -EMSGSIZE;
 				goto out;
 			}
@@ -939,7 +941,8 @@ static void zcrypt_msgtype6_receive_ep11(struct ap_queue *aq,
 			len = t86r->fmt2.offset1 + t86r->fmt2.count1;
 			if (len > reply->bufsize || len > msg->bufsize ||
 			    len != reply->len) {
-				ZCRYPT_DBF_DBG("%s len mismatch => EMSGSIZE\n", __func__);
+				pr_debug("%s len mismatch => EMSGSIZE\n",
+					 __func__);
 				msg->rc = -EMSGSIZE;
 				goto out;
 			}
@@ -1151,9 +1154,9 @@ static long zcrypt_msgtype6_send_cprb(bool userspace, struct zcrypt_queue *zq,
 
 out:
 	if (rc)
-		ZCRYPT_DBF_DBG("%s send cprb at dev=%02x.%04x rc=%d\n",
-			       __func__, AP_QID_CARD(zq->queue->qid),
-			       AP_QID_QUEUE(zq->queue->qid), rc);
+		pr_debug("%s send cprb at dev=%02x.%04x rc=%d\n",
+			 __func__, AP_QID_CARD(zq->queue->qid),
+			 AP_QID_QUEUE(zq->queue->qid), rc);
 	return rc;
 }
 
@@ -1274,9 +1277,9 @@ static long zcrypt_msgtype6_send_ep11_cprb(bool userspace, struct zcrypt_queue *
 
 out:
 	if (rc)
-		ZCRYPT_DBF_DBG("%s send cprb at dev=%02x.%04x rc=%d\n",
-			       __func__, AP_QID_CARD(zq->queue->qid),
-			       AP_QID_QUEUE(zq->queue->qid), rc);
+		pr_debug("%s send cprb at dev=%02x.%04x rc=%d\n",
+			 __func__, AP_QID_CARD(zq->queue->qid),
+			 AP_QID_QUEUE(zq->queue->qid), rc);
 	return rc;
 }