lkml.org 
[lkml]   [2013]   [Dec]   [2]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
From
Subject[PATCH v2 tty-next 7/8] n_tty: Extend debug tracing
Date
Add configurable trace support to allow tracing with dev_dbg,
pr_dbg, or trace_printk. Instrument .receive_buf() and read()
paths with traces to aid in debugging flow control changes.

Signed-off-by: Peter Hurley <peter@hurleysoftware.com>
---
drivers/tty/n_tty.c | 79 ++++++++++++++++++++++++++++++++++++++++++-----------
1 file changed, 63 insertions(+), 16 deletions(-)

diff --git a/drivers/tty/n_tty.c b/drivers/tty/n_tty.c
index 5254082..26ae9d7 100644
--- a/drivers/tty/n_tty.c
+++ b/drivers/tty/n_tty.c
@@ -80,12 +80,18 @@
#define ECHO_BLOCK 256
#define ECHO_DISCARD_WATERMARK N_TTY_BUF_SIZE - (ECHO_BLOCK + 32)

+#define n_tty_trace_facility trace_printk
+#define _n_tty_trace(tty, f, args...) \
+ do { \
+ char buf[64]; \
+ n_tty_trace_facility("[%s] " f, tty_name(tty, buf), ##args); \
+ } while (0)

#undef N_TTY_TRACE
#ifdef N_TTY_TRACE
-# define n_tty_trace(f, args...) trace_printk(f, ##args)
+# define n_tty_trace(tty, f, args...) _n_tty_trace(tty, f, args)
#else
-# define n_tty_trace(f, args...)
+# define n_tty_trace(tty, f, args...) do { } while (0)
#endif

struct n_tty_data {
@@ -179,8 +185,13 @@ static int receive_room(struct tty_struct *tty)
* that erase characters will be handled. Other excess
* characters will be beeped.
*/
- if (left <= 0)
+ if (left <= 0) {
left = ldata->icanon && ldata->canon_head == ldata->read_tail;
+ if (left) {
+ n_tty_trace(tty, "overflow, head:%zu tail:%zu\n",
+ ldata->read_head, ldata->read_tail);
+ }
+ }

return left;
}
@@ -200,11 +211,14 @@ static int receive_room(struct tty_struct *tty)
static void n_tty_set_room(struct tty_struct *tty)
{
struct n_tty_data *ldata = tty->disc_data;
+ int avail;

/* Did this open up the receive buffer? We may need to flip */
- if (unlikely(ldata->no_room) && receive_room(tty)) {
+ if (unlikely(ldata->no_room) && (avail = receive_room(tty))) {
ldata->no_room = 0;

+ n_tty_trace(tty, "restart worker (avail = %d)\n", avail);
+
WARN_RATELIMIT(tty->port->itty == NULL,
"scheduling with invalid itty\n");
/* see if ldisc has been killed - if so, this means that
@@ -240,6 +254,8 @@ static ssize_t chars_in_buffer(struct tty_struct *tty)

static void n_tty_write_wakeup(struct tty_struct *tty)
{
+ n_tty_trace(tty, "\n");
+
if (tty->fasync && test_and_clear_bit(TTY_DO_WRITE_WAKEUP, &tty->flags))
kill_fasync(&tty->fasync, SIGIO, POLL_OUT);
}
@@ -254,13 +270,16 @@ static void n_tty_check_throttle(struct tty_struct *tty)
* canonical mode and don't have a newline yet!
*/
while (1) {
- int throttled;
+ int throttled, avail;
tty_set_flow_change(tty, TTY_THROTTLE_SAFE);
- if (receive_room(tty) >= TTY_THRESHOLD_THROTTLE)
+ avail = receive_room(tty);
+ if (avail >= TTY_THRESHOLD_THROTTLE)
break;
throttled = tty_throttle_safe(tty);
- if (!throttled)
+ if (!throttled) {
+ n_tty_trace(tty, "throttled (avail = %d)/n", avail);
break;
+ }
}
__tty_set_flow_change(tty, 0);
}
@@ -289,16 +308,19 @@ static void n_tty_check_unthrottle(struct tty_struct *tty)
*/

while (1) {
- int unthrottled;
+ int unthrottled, used;
tty_set_flow_change(tty, TTY_UNTHROTTLE_SAFE);
- if (chars_in_buffer(tty) > TTY_THRESHOLD_UNTHROTTLE)
+ used = chars_in_buffer(tty);
+ if (used > TTY_THRESHOLD_UNTHROTTLE)
break;
if (!tty->count)
break;
n_tty_set_room(tty);
unthrottled = tty_unthrottle_safe(tty);
- if (!unthrottled)
+ if (!unthrottled) {
+ n_tty_trace(tty, "unthrottled (used = %d)\n", used);
break;
+ }
}
__tty_set_flow_change(tty, 0);
}
@@ -374,6 +396,9 @@ static void n_tty_packet_mode_flush(struct tty_struct *tty)
static void n_tty_flush_buffer(struct tty_struct *tty)
{
down_write(&tty->termios_rwsem);
+
+ n_tty_trace(tty, "\n");
+
reset_buffer_flags(tty->disc_data);
n_tty_set_room(tty);

@@ -770,6 +795,10 @@ static size_t __process_echoes(struct tty_struct *tty)
* of echo overrun before the next commit), then discard enough
* data at the tail to prevent a subsequent overrun */
while (ldata->echo_commit - tail >= ECHO_DISCARD_WATERMARK) {
+
+ n_tty_trace(tty, "discard echoes (%zu - %zu > %d)\n",
+ ldata->echo_commit, tail, ECHO_DISCARD_WATERMARK);
+
if (echo_buf(ldata, tail) == ECHO_OP_START) {
if (echo_buf(ldata, tail + 1) == ECHO_OP_ERASE_TAB)
tail += 3;
@@ -1369,6 +1398,7 @@ handle_newline:
set_bit(ldata->read_head & (N_TTY_BUF_SIZE - 1), ldata->read_flags);
put_tty_queue(c, ldata);
ldata->canon_head = ldata->read_head;
+ n_tty_trace(tty, "canon_head:%zu\n", ldata->canon_head);
kill_fasync(&tty->fasync, SIGIO, POLL_IN);
if (waitqueue_active(&tty->read_wait))
wake_up_interruptible(&tty->read_wait);
@@ -1670,6 +1700,7 @@ static void __receive_buf(struct tty_struct *tty, const unsigned char *cp,

if ((!ldata->icanon && (read_cnt(ldata) >= ldata->minimum_to_wake)) ||
L_EXTPROC(tty)) {
+ n_tty_trace(tty, "reader wakeup, count:%zd\n", read_cnt(ldata));
kill_fasync(&tty->fasync, SIGIO, POLL_IN);
if (waitqueue_active(&tty->read_wait))
wake_up_interruptible(&tty->read_wait);
@@ -1689,6 +1720,8 @@ n_tty_receive_buf_common(struct tty_struct *tty, const unsigned char *cp,
room = receive_room(tty);
n = min(count, room);
if (!n) {
+ if (!room)
+ n_tty_trace(tty, "buffer full\n");
if (flow && !room)
ldata->no_room = 1;
break;
@@ -1705,6 +1738,8 @@ n_tty_receive_buf_common(struct tty_struct *tty, const unsigned char *cp,
n_tty_check_throttle(tty);
up_read(&tty->termios_rwsem);

+ n_tty_trace(tty, "rcvd:%d\n", rcvd);
+
return rcvd;
}

@@ -1814,6 +1849,10 @@ static void n_tty_set_termios(struct tty_struct *tty, struct ktermios *old)
if (!I_IXON(tty) && old && (old->c_iflag & IXON) && !tty->flow_stopped)
start_tty(tty);

+ n_tty_trace(tty, "mode:%s tail:%zu canon:%zu head:%zu\n",
+ ldata->icanon ? "canon" : "raw", ldata->read_tail,
+ ldata->canon_head, ldata->read_head);
+
/* The termios change make the tty ready for I/O */
if (waitqueue_active(&tty->write_wait))
wake_up_interruptible(&tty->write_wait);
@@ -1893,10 +1932,14 @@ static inline int input_available_p(struct tty_struct *tty, int poll)
int amt = poll && !TIME_CHAR(tty) ? MIN_CHAR(tty) : 1;

if (ldata->icanon && !L_EXTPROC(tty)) {
- if (ldata->canon_head != ldata->read_tail)
+ if (ldata->canon_head != ldata->read_tail) {
+ n_tty_trace(tty, "line avail\n");
return 1;
- } else if (read_cnt(ldata) >= amt)
+ }
+ } else if (read_cnt(ldata) >= amt) {
+ n_tty_trace(tty, "avail:%zu amt:%d\n", read_cnt(ldata), amt);
return 1;
+ }

return 0;
}
@@ -1993,8 +2036,8 @@ static int canon_copy_from_read_buf(struct tty_struct *tty,
tail = ldata->read_tail & (N_TTY_BUF_SIZE - 1);
size = min_t(size_t, tail + n, N_TTY_BUF_SIZE);

- n_tty_trace("%s: nr:%zu tail:%zu n:%zu size:%zu\n",
- __func__, *nr, tail, n, size);
+ n_tty_trace(tty, "nr:%zu tail:%zu n:%zu size:%zu\n",
+ *nr, tail, n, size);

eol = find_next_bit(ldata->read_flags, size, tail);
more = n - (size - tail);
@@ -2018,8 +2061,8 @@ static int canon_copy_from_read_buf(struct tty_struct *tty,
eof_push = !n && ldata->read_tail != ldata->line_start;
}

- n_tty_trace("%s: eol:%zu found:%d n:%zu c:%zu size:%zu more:%zu\n",
- __func__, eol, found, n, c, size, more);
+ n_tty_trace(tty, "eol:%zu found:%d n:%zu c:%zu size:%zu more:%zu\n",
+ eol, found, n, c, size, more);

if (n > size) {
ret = copy_to_user(*b, read_buf_addr(ldata, tail), size);
@@ -2211,6 +2254,8 @@ static ssize_t n_tty_read(struct tty_struct *tty, struct file *file,
n_tty_set_room(tty);
up_read(&tty->termios_rwsem);

+ n_tty_trace(tty, "blocking\n");
+
timeout = schedule_timeout(timeout);

down_read(&tty->termios_rwsem);
@@ -2268,6 +2313,8 @@ static ssize_t n_tty_read(struct tty_struct *tty, struct file *file,
if (b - buf)
retval = b - buf;

+ n_tty_trace(tty, "ret:%zd\n", retval);
+
return retval;
}

--
1.8.1.2


\
 
 \ /
  Last update: 2013-12-03 07:41    [W:0.189 / U:0.028 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site