Bluetooth: Add debug output to ERTM code

Use the dynamic debug to output info about ERTM protocol stuff.
The following script can be used to enable debug for ERTM:

DEBUGFS="/sys/kernel/debug/dynamic_debug/control"

echo -n 'func l2cap_send_disconn_req +p' > $DEBUGFS
echo -n 'func l2cap_monitor_timeout +p' > $DEBUGFS
echo -n 'func l2cap_retrans_timeout +p' > $DEBUGFS
echo -n 'func l2cap_busy_work  +p' > $DEBUGFS
echo -n 'func l2cap_push_rx_skb +p' > $DEBUGFS
echo -n 'func l2cap_data_channel_iframe +p' > $DEBUGFS
echo -n 'func l2cap_data_channel_rrframe +p' > $DEBUGFS
echo -n 'func l2cap_data_channel_rejframe +p' > $DEBUGFS
echo -n 'func l2cap_data_channel_srejframe +p' > $DEBUGFS
echo -n 'func l2cap_data_channel_rnrframe +p' > $DEBUGFS

Signed-off-by: Gustavo F. Padovan <padovan@profusion.mobi>
Reviewed-by: João Paulo Rechi Vita <jprvita@profusion.mobi>
Signed-off-by: Marcel Holtmann <marcel@holtmann.org>

1 files changed, 22 insertions, 1 deletions

diff --git a/net/bluetooth/l2cap.c b/net/bluetooth/l2cap.c
index 1e39d72b80af..6e8a0512a9c9 100644
--- a/net/bluetooth/l2cap.c
+++ b/net/bluetooth/l2cap.c
@@ -1314,6 +1314,8 @@ static void l2cap_monitor_timeout(unsigned long arg)
 {
         struct sock *sk = (void *) arg;
 
+        BT_DBG("sk %p", sk);
+
         bh_lock_sock(sk);
         if (l2cap_pi(sk)->retry_count >= l2cap_pi(sk)->remote_max_tx) {
                 l2cap_send_disconn_req(l2cap_pi(sk)->conn, sk, ECONNABORTED);
@@ -1332,6 +1334,8 @@ static void l2cap_retrans_timeout(unsigned long arg)
 {
         struct sock *sk = (void *) arg;
 
+        BT_DBG("sk %p", sk);
+
         bh_lock_sock(sk);
         l2cap_pi(sk)->retry_count = 1;
         __mod_monitor_timer();
@@ -3645,6 +3649,8 @@ done:
         pi->conn_state &= ~L2CAP_CONN_LOCAL_BUSY;
         pi->conn_state &= ~L2CAP_CONN_RNR_SENT;
 
+        BT_DBG("sk %p, Exit local busy", sk);
+
         set_current_state(TASK_RUNNING);
         remove_wait_queue(sk_sleep(sk), &wait);
 
@@ -3669,6 +3675,8 @@ static int l2cap_push_rx_skb(struct sock *sk, struct sk_buff *skb, u16 control)
         }
 
         /* Busy Condition */
+        BT_DBG("sk %p, Enter local busy", sk);
+
         pi->conn_state |= L2CAP_CONN_LOCAL_BUSY;
         bt_cb(skb)->sar = control >> L2CAP_CTRL_SAR_SHIFT;
         __skb_queue_tail(BUSY_QUEUE(sk), skb);
@@ -3847,7 +3855,8 @@ static inline int l2cap_data_channel_iframe(struct sock *sk, u16 rx_control, str
         int num_to_ack = (pi->tx_win/6) + 1;
         int err = 0;
 
-        BT_DBG("sk %p rx_control 0x%4.4x len %d", sk, rx_control, skb->len);
+        BT_DBG("sk %p len %d tx_seq %d rx_control 0x%4.4x", sk, skb->len, tx_seq,
+                                                                rx_control);
 
         if (L2CAP_CTRL_FINAL & rx_control &&
                         l2cap_pi(sk)->conn_state & L2CAP_CONN_WAIT_F) {
@@ -3892,6 +3901,7 @@ static inline int l2cap_data_channel_iframe(struct sock *sk, u16 rx_control, str
                                 pi->buffer_seq = pi->buffer_seq_srej;
                                 pi->conn_state &= ~L2CAP_CONN_SREJ_SENT;
                                 l2cap_send_ack(pi);
+                                BT_DBG("sk %p, Exit SREJ_SENT", sk);
                         }
                 } else {
                         struct srej_list *l;
@@ -3920,6 +3930,8 @@ static inline int l2cap_data_channel_iframe(struct sock *sk, u16 rx_control, str
 
                 pi->conn_state |= L2CAP_CONN_SREJ_SENT;
 
+                BT_DBG("sk %p, Enter SREJ", sk);
+
                 INIT_LIST_HEAD(SREJ_LIST(sk));
                 pi->buffer_seq_srej = pi->buffer_seq;
 
@@ -3973,6 +3985,9 @@ static inline void l2cap_data_channel_rrframe(struct sock *sk, u16 rx_control)
 {
         struct l2cap_pinfo *pi = l2cap_pi(sk);
 
+        BT_DBG("sk %p, req_seq %d ctrl 0x%4.4x", sk, __get_reqseq(rx_control),
+                                                rx_control);
+
         pi->expected_ack_seq = __get_reqseq(rx_control);
         l2cap_drop_acked_frames(sk);
 
@@ -4018,6 +4033,8 @@ static inline void l2cap_data_channel_rejframe(struct sock *sk, u16 rx_control)
         struct l2cap_pinfo *pi = l2cap_pi(sk);
         u8 tx_seq = __get_reqseq(rx_control);
 
+        BT_DBG("sk %p, req_seq %d ctrl 0x%4.4x", sk, tx_seq, rx_control);
+
         pi->conn_state &= ~L2CAP_CONN_REMOTE_BUSY;
 
         pi->expected_ack_seq = tx_seq;
@@ -4040,6 +4057,8 @@ static inline void l2cap_data_channel_srejframe(struct sock *sk, u16 rx_control)
         struct l2cap_pinfo *pi = l2cap_pi(sk);
         u8 tx_seq = __get_reqseq(rx_control);
 
+        BT_DBG("sk %p, req_seq %d ctrl 0x%4.4x", sk, tx_seq, rx_control);
+
         pi->conn_state &= ~L2CAP_CONN_REMOTE_BUSY;
 
         if (rx_control & L2CAP_CTRL_POLL) {
@@ -4077,6 +4096,8 @@ static inline void l2cap_data_channel_rnrframe(struct sock *sk, u16 rx_control)
         struct l2cap_pinfo *pi = l2cap_pi(sk);
         u8 tx_seq = __get_reqseq(rx_control);
 
+        BT_DBG("sk %p, req_seq %d ctrl 0x%4.4x", sk, tx_seq, rx_control);
+
         pi->conn_state |= L2CAP_CONN_REMOTE_BUSY;
         pi->expected_ack_seq = tx_seq;
         l2cap_drop_acked_frames(sk);