[PATCH 0/7] tty core debug patches

[PATCH 0/7] tty core debug patches

[Peter Hurley]

Hi Greg,

This patchset replaces the printk(KERN_DEBUG) uses in the tty core
with a common tty_debug(tty, ...) base macro, folding in the common
elements of tty name and function name.

The many inline #ifdef TTY_SOME_DEBUG_FLAG printk's are replaced
with macro equivalents which reduce to tty_debug().

Several important improvements include:
* patch 1/7 adds the tty count to the tty_open() message
* patch 6/7 improve the ldisc messages to aid in state debugging
* patch 7/7 adds pmtx open (which helps clarify when the master was opened)

An important outcome of a single tty_debug() macro is that it can
be trivially changed to use a different debug facility than console;
for example, for some of my torture tests using the ftrace facility
is much less intrusive. I would expect that to remain a local change though.

Regards,

Peter Hurley (7):
  tty: core: Improve debug message content
  tty: core: Add tty_debug() for printk(KERN_DEBUG) messages
  tty: Replace #ifdef TTY_DEBUG_HANGUP with tty_debug_hangup()
  tty: Use tty_debug() for tty_ldisc_debug()
  tty: Replace inline #ifdef TTY_DEBUG_WAIT_UNTIL_SENT
  tty: core: Improve ldisc debug messages
  pty: Add debug message for ptmx open

 drivers/tty/pty.c       |  8 ++++++
 drivers/tty/tty_io.c    | 67 +++++++++++++++++++------------------------------
 drivers/tty/tty_ioctl.c | 11 +++++---
 drivers/tty/tty_ldisc.c | 15 ++++++-----
 include/linux/tty.h     |  6 +++++
 5 files changed, 55 insertions(+), 52 deletions(-)

-- 
2.4.5

[PATCH 1/7] tty: core: Improve debug message content

[Peter Hurley]

Output the function name, tty name, and invariant failure (if applicable).
Add the tty count to the tty_open() message. Fix the disassociate_ctty()
message, which printed the NULL pointer and the wrong message.

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

diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
index 57fc6ee..2d9811a 100644
--- a/drivers/tty/tty_io.c
+++ b/drivers/tty/tty_io.c
@@ -524,7 +524,8 @@ static void __proc_set_tty(struct tty_struct *tty)
 	spin_unlock_irqrestore(&tty->ctrl_lock, flags);
 	tty->session = get_pid(task_session(current));
 	if (current->signal->tty) {
-		printk(KERN_DEBUG "tty not NULL!!\n");
+		printk(KERN_DEBUG "%s: %s: current tty %s not NULL!!\n",
+		       __func__, tty->name, current->signal->tty->name);
 		tty_kref_put(current->signal->tty);
 	}
 	put_pid(current->signal->tty_old_pgrp);
@@ -922,8 +923,7 @@ void disassociate_ctty(int on_exit)
 		tty_kref_put(tty);
 	} else {
 #ifdef TTY_DEBUG_HANGUP
-		printk(KERN_DEBUG "error attempted to write to tty [0x%p]"
-		       " = NULL", tty);
+		printk(KERN_DEBUG "%s: no current tty\n", __func__);
 #endif
 	}
 
@@ -1705,8 +1705,8 @@ static int tty_release_checks(struct tty_struct *tty, int idx)
 {
 #ifdef TTY_PARANOIA_CHECK
 	if (idx < 0 || idx >= tty->driver->num) {
-		printk(KERN_DEBUG "%s: bad idx when trying to free (%s)\n",
-				__func__, tty->name);
+		printk(KERN_DEBUG "%s: %s: bad idx %d\n",
+				__func__, tty->name, idx);
 		return -1;
 	}
 
@@ -1715,20 +1715,22 @@ static int tty_release_checks(struct tty_struct *tty, int idx)
 		return 0;
 
 	if (tty != tty->driver->ttys[idx]) {
-		printk(KERN_DEBUG "%s: driver.table[%d] not tty for (%s)\n",
-				__func__, idx, tty->name);
+		printk(KERN_DEBUG "%s: %s: bad driver table[%d] = %p\n",
+		       __func__, tty->name, idx, tty->driver->ttys[idx]);
 		return -1;
 	}
 	if (tty->driver->other) {
 		struct tty_struct *o_tty = tty->link;
 
 		if (o_tty != tty->driver->other->ttys[idx]) {
-			printk(KERN_DEBUG "%s: other->table[%d] not o_tty for (%s)\n",
-					__func__, idx, tty->name);
+			printk(KERN_DEBUG "%s: %s: bad other table[%d] = %p\n",
+			       __func__, tty->name, idx,
+			       tty->driver->other->ttys[idx]);
 			return -1;
 		}
 		if (o_tty->link != tty) {
-			printk(KERN_DEBUG "%s: bad pty pointers\n", __func__);
+			printk(KERN_DEBUG "%s: %s: bad link = %p\n",
+			       __func__, tty->name, o_tty->link);
 			return -1;
 		}
 	}
@@ -2099,7 +2101,8 @@ retry_open:
 	    tty->driver->subtype == PTY_TYPE_MASTER)
 		noctty = 1;
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s: opening %s...\n", __func__, tty->name);
+	printk(KERN_DEBUG "%s: %s: (tty count=%d)\n", __func__, tty->name,
+	       tty->count);
 #endif
 	if (tty->ops->open)
 		retval = tty->ops->open(tty, filp);
@@ -2109,8 +2112,8 @@ retry_open:
 
 	if (retval) {
 #ifdef TTY_DEBUG_HANGUP
-		printk(KERN_DEBUG "%s: error %d in opening %s...\n", __func__,
-				retval, tty->name);
+		printk(KERN_DEBUG "%s: %s: error %d, releasing...\n", __func__,
+		       tty->name, retval);
 #endif
 		tty_unlock(tty); /* need to call tty_release without BTM */
 		tty_release(inode, filp);
-- 
2.4.5

[PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Peter Hurley]

Introduce tty_debug() macro to output uniform debug information for
tty core debug messages (function name and tty name).

Note: printk(KERN_DEBUG) is retained here over pr_debug() since
messages can be enabled in non-DEBUG builds.

Signed-off-by: Peter Hurley <peter@hurleysoftware.com>
---
 drivers/tty/tty_io.c | 41 +++++++++++++++++------------------------
 include/linux/tty.h  |  6 ++++++
 2 files changed, 23 insertions(+), 24 deletions(-)

diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
index 2d9811a..6de2c36 100644
--- a/drivers/tty/tty_io.c
+++ b/drivers/tty/tty_io.c
@@ -524,8 +524,8 @@ static void __proc_set_tty(struct tty_struct *tty)
 	spin_unlock_irqrestore(&tty->ctrl_lock, flags);
 	tty->session = get_pid(task_session(current));
 	if (current->signal->tty) {
-		printk(KERN_DEBUG "%s: %s: current tty %s not NULL!!\n",
-		       __func__, tty->name, current->signal->tty->name);
+		tty_debug(tty, "current tty %s not NULL!!\n",
+			  current->signal->tty->name);
 		tty_kref_put(current->signal->tty);
 	}
 	put_pid(current->signal->tty_old_pgrp);
@@ -768,7 +768,7 @@ static void do_tty_hangup(struct work_struct *work)
 void tty_hangup(struct tty_struct *tty)
 {
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s hangup...\n", tty_name(tty));
+	tty_debug(tty, "\n");
 #endif
 	schedule_work(&tty->hangup_work);
 }
@@ -787,7 +787,7 @@ EXPORT_SYMBOL(tty_hangup);
 void tty_vhangup(struct tty_struct *tty)
 {
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s vhangup...\n", tty_name(tty));
+	tty_debug(tty, "\n")
 #endif
 	__tty_hangup(tty, 0);
 }
@@ -826,7 +826,7 @@ void tty_vhangup_self(void)
 static void tty_vhangup_session(struct tty_struct *tty)
 {
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s vhangup session...\n", tty_name(tty));
+	tty_debug(tty, "\n");
 #endif
 	__tty_hangup(tty, 1);
 }
@@ -923,7 +923,7 @@ void disassociate_ctty(int on_exit)
 		tty_kref_put(tty);
 	} else {
 #ifdef TTY_DEBUG_HANGUP
-		printk(KERN_DEBUG "%s: no current tty\n", __func__);
+		tty_debug(tty, "no current tty\n");
 #endif
 	}
 
@@ -1705,8 +1705,7 @@ static int tty_release_checks(struct tty_struct *tty, int idx)
 {
 #ifdef TTY_PARANOIA_CHECK
 	if (idx < 0 || idx >= tty->driver->num) {
-		printk(KERN_DEBUG "%s: %s: bad idx %d\n",
-				__func__, tty->name, idx);
+		tty_debug(tty, "bad idx %d\n", idx);
 		return -1;
 	}
 
@@ -1715,22 +1714,20 @@ static int tty_release_checks(struct tty_struct *tty, int idx)
 		return 0;
 
 	if (tty != tty->driver->ttys[idx]) {
-		printk(KERN_DEBUG "%s: %s: bad driver table[%d] = %p\n",
-		       __func__, tty->name, idx, tty->driver->ttys[idx]);
+		tty_debug(tty, "bad driver table[%d] = %p\n",
+			  idx, tty->driver->ttys[idx]);
 		return -1;
 	}
 	if (tty->driver->other) {
 		struct tty_struct *o_tty = tty->link;
 
 		if (o_tty != tty->driver->other->ttys[idx]) {
-			printk(KERN_DEBUG "%s: %s: bad other table[%d] = %p\n",
-			       __func__, tty->name, idx,
-			       tty->driver->other->ttys[idx]);
+			tty_debug(tty, "bad other table[%d] = %p\n",
+				  idx, tty->driver->other->ttys[idx]);
 			return -1;
 		}
 		if (o_tty->link != tty) {
-			printk(KERN_DEBUG "%s: %s: bad link = %p\n",
-			       __func__, tty->name, o_tty->link);
+			tty_debug(tty, "bad link = %p\n", o_tty->link);
 			return -1;
 		}
 	}
@@ -1785,8 +1782,7 @@ int tty_release(struct inode *inode, struct file *filp)
 	}
 
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s: %s (tty count=%d)...\n", __func__,
-			tty_name(tty), tty->count);
+	tty_debug(tty, "(tty count=%d)...\n", tty->count);
 #endif
 
 	if (tty->ops->close)
@@ -1898,7 +1894,7 @@ int tty_release(struct inode *inode, struct file *filp)
 		return 0;
 
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s: %s: final close\n", __func__, tty_name(tty));
+	tty_debug(tty, "final close\n");
 #endif
 	/*
 	 * Ask the line discipline code to release its structures
@@ -1909,8 +1905,7 @@ int tty_release(struct inode *inode, struct file *filp)
 	tty_flush_works(tty);
 
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s: %s: freeing structure...\n", __func__,
-	       tty_name(tty));
+	tty_debug(tty, "freeing structure...\n");
 #endif
 	/*
 	 * The release_tty function takes care of the details of clearing
@@ -2101,8 +2096,7 @@ retry_open:
 	    tty->driver->subtype == PTY_TYPE_MASTER)
 		noctty = 1;
 #ifdef TTY_DEBUG_HANGUP
-	printk(KERN_DEBUG "%s: %s: (tty count=%d)\n", __func__, tty->name,
-	       tty->count);
+	tty_debug(tty, "(tty count=%d)\n", tty->count);
 #endif
 	if (tty->ops->open)
 		retval = tty->ops->open(tty, filp);
@@ -2112,8 +2106,7 @@ retry_open:
 
 	if (retval) {
 #ifdef TTY_DEBUG_HANGUP
-		printk(KERN_DEBUG "%s: %s: error %d, releasing...\n", __func__,
-		       tty->name, retval);
+		tty_debug(tty, "error %d, releasing...\n", retval);
 #endif
 		tty_unlock(tty); /* need to call tty_release without BTM */
 		tty_release(inode, filp);
diff --git a/include/linux/tty.h b/include/linux/tty.h
index ad6c891..d072ded 100644
--- a/include/linux/tty.h
+++ b/include/linux/tty.h
@@ -709,4 +709,10 @@ static inline void proc_tty_register_driver(struct tty_driver *d) {}
 static inline void proc_tty_unregister_driver(struct tty_driver *d) {}
 #endif
 
+#define tty_debug(tty, f, args...)					\
+	do {								\
+		printk(KERN_DEBUG "%s: %s: " f, __func__,		\
+		       tty_name(tty), ##args);				\
+	} while (0)
+
 #endif
-- 
2.4.5

[PATCH 3/7] tty: Replace #ifdef TTY_DEBUG_HANGUP with tty_debug_hangup()

[Peter Hurley]

Add tty_debug_hangup() macro which uses tty_debug to print the
debug message; remove inlined #ifdefs.

Signed-off-by: Peter Hurley <peter@hurleysoftware.com>
---
 drivers/tty/tty_io.c | 47 ++++++++++++++++++-----------------------------
 1 file changed, 18 insertions(+), 29 deletions(-)

diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
index 6de2c36..acd6988 100644
--- a/drivers/tty/tty_io.c
+++ b/drivers/tty/tty_io.c
@@ -106,6 +106,11 @@
 #include <linux/nsproxy.h>
 
 #undef TTY_DEBUG_HANGUP
+#ifdef TTY_DEBUG_HANGUP
+# define tty_debug_hangup(tty, f, args...)	tty_debug(tty, f, ##args)
+#else
+# define tty_debug_hangup(tty, f, args...)	do { } while (0)
+#endif
 
 #define TTY_PARANOIA_CHECK 1
 #define CHECK_TTY_COUNT 1
@@ -767,9 +772,7 @@ static void do_tty_hangup(struct work_struct *work)
 
 void tty_hangup(struct tty_struct *tty)
 {
-#ifdef TTY_DEBUG_HANGUP
-	tty_debug(tty, "\n");
-#endif
+	tty_debug_hangup(tty, "\n");
 	schedule_work(&tty->hangup_work);
 }
 
@@ -786,9 +789,7 @@ EXPORT_SYMBOL(tty_hangup);
 
 void tty_vhangup(struct tty_struct *tty)
 {
-#ifdef TTY_DEBUG_HANGUP
-	tty_debug(tty, "\n")
-#endif
+	tty_debug_hangup(tty, "\n");
 	__tty_hangup(tty, 0);
 }
 
@@ -825,9 +826,7 @@ void tty_vhangup_self(void)
 
 static void tty_vhangup_session(struct tty_struct *tty)
 {
-#ifdef TTY_DEBUG_HANGUP
-	tty_debug(tty, "\n");
-#endif
+	tty_debug_hangup(tty, "\n");
 	__tty_hangup(tty, 1);
 }
 
@@ -921,11 +920,8 @@ void disassociate_ctty(int on_exit)
 		tty->pgrp = NULL;
 		spin_unlock_irqrestore(&tty->ctrl_lock, flags);
 		tty_kref_put(tty);
-	} else {
-#ifdef TTY_DEBUG_HANGUP
-		tty_debug(tty, "no current tty\n");
-#endif
-	}
+	} else
+		tty_debug_hangup(tty, "no current tty\n");
 
 	spin_unlock_irq(&current->sighand->siglock);
 	/* Now clear signal->tty under the lock */
@@ -1781,9 +1777,7 @@ int tty_release(struct inode *inode, struct file *filp)
 		return 0;
 	}
 
-#ifdef TTY_DEBUG_HANGUP
-	tty_debug(tty, "(tty count=%d)...\n", tty->count);
-#endif
+	tty_debug_hangup(tty, "(tty count=%d)...\n", tty->count);
 
 	if (tty->ops->close)
 		tty->ops->close(tty, filp);
@@ -1893,9 +1887,7 @@ int tty_release(struct inode *inode, struct file *filp)
 	if (!final)
 		return 0;
 
-#ifdef TTY_DEBUG_HANGUP
-	tty_debug(tty, "final close\n");
-#endif
+	tty_debug_hangup(tty, "final close\n");
 	/*
 	 * Ask the line discipline code to release its structures
 	 */
@@ -1904,9 +1896,7 @@ int tty_release(struct inode *inode, struct file *filp)
 	/* Wait for pending work before tty destruction commmences */
 	tty_flush_works(tty);
 
-#ifdef TTY_DEBUG_HANGUP
-	tty_debug(tty, "freeing structure...\n");
-#endif
+	tty_debug_hangup(tty, "freeing structure...\n");
 	/*
 	 * The release_tty function takes care of the details of clearing
 	 * the slots and preserving the termios structure. The tty_unlock_pair
@@ -2095,9 +2085,9 @@ retry_open:
 	if (tty->driver->type == TTY_DRIVER_TYPE_PTY &&
 	    tty->driver->subtype == PTY_TYPE_MASTER)
 		noctty = 1;
-#ifdef TTY_DEBUG_HANGUP
-	tty_debug(tty, "(tty count=%d)\n", tty->count);
-#endif
+
+	tty_debug_hangup(tty, "(tty count=%d)\n", tty->count);
+
 	if (tty->ops->open)
 		retval = tty->ops->open(tty, filp);
 	else
@@ -2105,9 +2095,8 @@ retry_open:
 	filp->f_flags = saved_flags;
 
 	if (retval) {
-#ifdef TTY_DEBUG_HANGUP
-		tty_debug(tty, "error %d, releasing...\n", retval);
-#endif
+		tty_debug_hangup(tty, "error %d, releasing...\n", retval);
+
 		tty_unlock(tty); /* need to call tty_release without BTM */
 		tty_release(inode, filp);
 		if (retval != -ERESTARTSYS)
-- 
2.4.5

[PATCH 4/7] tty: Use tty_debug() for tty_ldisc_debug()

[Peter Hurley]

Replace tty_ldisc_debug() macro definition; substitute with equivalent
tty_debug() invocation.

Signed-off-by: Peter Hurley <peter@hurleysoftware.com>
---
 drivers/tty/tty_ldisc.c | 4 +---
 1 file changed, 1 insertion(+), 3 deletions(-)

diff --git a/drivers/tty/tty_ldisc.c b/drivers/tty/tty_ldisc.c
index c07fb5d..8191680 100644
--- a/drivers/tty/tty_ldisc.c
+++ b/drivers/tty/tty_ldisc.c
@@ -22,9 +22,7 @@
 #undef LDISC_DEBUG_HANGUP
 
 #ifdef LDISC_DEBUG_HANGUP
-#define tty_ldisc_debug(tty, f, args...) ({				  \
-	printk(KERN_DEBUG "%s: %s: " f, __func__, tty_name(tty), ##args); \
-})
+#define tty_ldisc_debug(tty, f, args...)	tty_debug(tty, f, ##args)
 #else
 #define tty_ldisc_debug(tty, f, args...)
 #endif
-- 
2.4.5

[PATCH 5/7] tty: Replace inline #ifdef TTY_DEBUG_WAIT_UNTIL_SENT

[Peter Hurley]

Add tty_debug_wait_until_sent() macro which uses tty_debug() to print
the debug message; remove inlined #ifdef.

Signed-off-by: Peter Hurley <peter@hurleysoftware.com>
---
 drivers/tty/tty_ioctl.c | 11 ++++++++---
 1 file changed, 8 insertions(+), 3 deletions(-)

diff --git a/drivers/tty/tty_ioctl.c b/drivers/tty/tty_ioctl.c
index 5232fb6..9c5aebf 100644
--- a/drivers/tty/tty_ioctl.c
+++ b/drivers/tty/tty_ioctl.c
@@ -26,6 +26,12 @@
 
 #undef TTY_DEBUG_WAIT_UNTIL_SENT
 
+#ifdef TTY_DEBUG_WAIT_UNTIL_SENT
+# define tty_debug_wait_until_sent(tty, f, args...)    tty_debug(tty, f, ##args)
+#else
+# define tty_debug_wait_until_sent(tty, f, args...)    do {} while (0)
+#endif
+
 #undef	DEBUG
 
 /*
@@ -210,9 +216,8 @@ int tty_unthrottle_safe(struct tty_struct *tty)
 
 void tty_wait_until_sent(struct tty_struct *tty, long timeout)
 {
-#ifdef TTY_DEBUG_WAIT_UNTIL_SENT
-	printk(KERN_DEBUG "%s wait until sent...\n", tty_name(tty));
-#endif
+	tty_debug_wait_until_sent(tty, "\n");
+
 	if (!timeout)
 		timeout = MAX_SCHEDULE_TIMEOUT;
 
-- 
2.4.5

[PATCH 6/7] tty: core: Improve ldisc debug messages

[Peter Hurley]

Add debug messages for ldisc open and close, and remove
"closing ldisc" message from tty_ldisc_release(), because a
close message is now printed for both ldiscs; always print ldisc
pointer first so ldisc changes are easier to identify.

Signed-off-by: Peter Hurley <peter@hurleysoftware.com>
---
 drivers/tty/tty_ldisc.c | 11 ++++++-----
 1 file changed, 6 insertions(+), 5 deletions(-)

diff --git a/drivers/tty/tty_ldisc.c b/drivers/tty/tty_ldisc.c
index 8191680..71750cb 100644
--- a/drivers/tty/tty_ldisc.c
+++ b/drivers/tty/tty_ldisc.c
@@ -447,6 +447,8 @@ static int tty_ldisc_open(struct tty_struct *tty, struct tty_ldisc *ld)
 		ret = ld->ops->open(tty);
 		if (ret)
 			clear_bit(TTY_LDISC_OPEN, &tty->flags);
+
+		tty_ldisc_debug(tty, "%p: opened\n", tty->ldisc);
 		return ret;
 	}
 	return 0;
@@ -467,6 +469,7 @@ static void tty_ldisc_close(struct tty_struct *tty, struct tty_ldisc *ld)
 	clear_bit(TTY_LDISC_OPEN, &tty->flags);
 	if (ld->ops->close)
 		ld->ops->close(tty);
+	tty_ldisc_debug(tty, "%p: closed\n", tty->ldisc);
 }
 
 /**
@@ -660,7 +663,7 @@ void tty_ldisc_hangup(struct tty_struct *tty)
 	int reset = tty->driver->flags & TTY_DRIVER_RESET_TERMIOS;
 	int err = 0;
 
-	tty_ldisc_debug(tty, "closing ldisc: %p\n", tty->ldisc);
+	tty_ldisc_debug(tty, "%p: closing\n", tty->ldisc);
 
 	ld = tty_ldisc_ref(tty);
 	if (ld != NULL) {
@@ -710,7 +713,7 @@ void tty_ldisc_hangup(struct tty_struct *tty)
 	if (reset)
 		tty_reset_termios(tty);
 
-	tty_ldisc_debug(tty, "re-opened ldisc: %p\n", tty->ldisc);
+	tty_ldisc_debug(tty, "%p: re-opened\n", tty->ldisc);
 }
 
 /**
@@ -774,8 +777,6 @@ void tty_ldisc_release(struct tty_struct *tty)
 	 * it does not race with the set_ldisc code path.
 	 */
 
-	tty_ldisc_debug(tty, "closing ldisc: %p\n", tty->ldisc);
-
 	tty_ldisc_lock_pair(tty, o_tty);
 	tty_ldisc_kill(tty);
 	if (o_tty)
@@ -785,7 +786,7 @@ void tty_ldisc_release(struct tty_struct *tty)
 	/* And the memory resources remaining (buffers, termios) will be
 	   disposed of when the kref hits zero */
 
-	tty_ldisc_debug(tty, "ldisc closed\n");
+	tty_ldisc_debug(tty, "released\n");
 }
 
 /**
-- 
2.4.5

[PATCH 7/7] pty: Add debug message for ptmx open

[Peter Hurley]

Opens of /dev/ptmx don't use tty_open() so debug messages are
not printed for those opens; print a debug message with the
open count (which must always be 1) if TTY_DEBUG_HANGUP is defined.

NB: Each tty core source file undefs support for debug messages.
The relevant source file must be patched/edited to enable these
messages.

Signed-off-by: Peter Hurley <peter@hurleysoftware.com>
---
 drivers/tty/pty.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/drivers/tty/pty.c b/drivers/tty/pty.c
index 4d5e840..4d5937c 100644
--- a/drivers/tty/pty.c
+++ b/drivers/tty/pty.c
@@ -26,6 +26,12 @@
 #include <linux/mutex.h>
 #include <linux/poll.h>
 
+#undef TTY_DEBUG_HANGUP
+#ifdef TTY_DEBUG_HANGUP
+# define tty_debug_hangup(tty, f, args...)	tty_debug(tty, f, ##args)
+#else
+# define tty_debug_hangup(tty, f, args...)	do {} while (0)
+#endif
 
 #ifdef CONFIG_UNIX98_PTYS
 static struct tty_driver *ptm_driver;
@@ -779,6 +785,8 @@ static int ptmx_open(struct inode *inode, struct file *filp)
 	if (retval)
 		goto err_release;
 
+	tty_debug_hangup(tty, "(tty count=%d)\n", tty->count);
+
 	tty_unlock(tty);
 	return 0;
 err_release:
-- 
2.4.5

Re: [PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Joe Perches]

On Sun, 2015-07-12 at 22:49 -0400, Peter Hurley wrote:
> Introduce tty_debug() macro to output uniform debug information for
> tty core debug messages (function name and tty name).
[]
> diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
[]
> @@ -768,7 +768,7 @@ static void do_tty_hangup(struct work_struct *work)
>  void tty_hangup(struct tty_struct *tty)
>  {
>  #ifdef TTY_DEBUG_HANGUP
> -	printk(KERN_DEBUG "%s hangup...\n", tty_name(tty));
> +	tty_debug(tty, "\n");

Why drop the "hangup..." ?

> diff --git a/include/linux/tty.h b/include/linux/tty.h
[]
> +#define tty_debug(tty, f, args...)					\
> +	do {								\
> +		printk(KERN_DEBUG "%s: %s: " f, __func__,		\
> +		       tty_name(tty), ##args);				\
> +	} while (0)

Single statement macros don't need do {} while (0)

#define fmt, ... 
using fmt, ##__VA_ARGS__

is more common.

Re: [PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Peter Hurley]

On 07/12/2015 11:47 PM, Joe Perches wrote:
> On Sun, 2015-07-12 at 22:49 -0400, Peter Hurley wrote:
>> Introduce tty_debug() macro to output uniform debug information for
>> tty core debug messages (function name and tty name).
> []
>> diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
> []
>> @@ -768,7 +768,7 @@ static void do_tty_hangup(struct work_struct *work)
>>  void tty_hangup(struct tty_struct *tty)
>>  {
>>  #ifdef TTY_DEBUG_HANGUP
>> -	printk(KERN_DEBUG "%s hangup...\n", tty_name(tty));
>> +	tty_debug(tty, "\n");
> 
> Why drop the "hangup..." ?

tty_debug() prints the function name; in this case, tty_hangup().


>> diff --git a/include/linux/tty.h b/include/linux/tty.h
> []
>> +#define tty_debug(tty, f, args...)					\
>> +	do {								\
>> +		printk(KERN_DEBUG "%s: %s: " f, __func__,		\
>> +		       tty_name(tty), ##args);				\
>> +	} while (0)
> 
> Single statement macros don't need do {} while (0)

Ah, yep. Old hold-over from when tty_name() needed a temp buffer.


> #define fmt, ... 
> using fmt, ##__VA_ARGS__
> 
> is more common.

Ok.

Regards,
Peter Hurley

Re: [PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Joe Perches]

On Mon, 2015-07-13 at 00:25 -0400, Peter Hurley wrote:
> On 07/12/2015 11:47 PM, Joe Perches wrote:
> > On Sun, 2015-07-12 at 22:49 -0400, Peter Hurley wrote:
> >> Introduce tty_debug() macro to output uniform debug information for
> >> tty core debug messages (function name and tty name).
> > []
> >> diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
> > []
> >> @@ -768,7 +768,7 @@ static void do_tty_hangup(struct work_struct *work)
> >>  void tty_hangup(struct tty_struct *tty)
> >>  {
> >>  #ifdef TTY_DEBUG_HANGUP
> >> -	printk(KERN_DEBUG "%s hangup...\n", tty_name(tty));
> >> +	tty_debug(tty, "\n");
> > 
> > Why drop the "hangup..." ?
> 
> tty_debug() prints the function name; in this case, tty_hangup().

maybe that #ifdef/#endif block could/should be removed
and the function tracer used to track this instead.

cheers, Joe

Re: [PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Peter Hurley]

On 07/13/2015 12:30 AM, Joe Perches wrote:
> On Mon, 2015-07-13 at 00:25 -0400, Peter Hurley wrote:
>> On 07/12/2015 11:47 PM, Joe Perches wrote:
>>> On Sun, 2015-07-12 at 22:49 -0400, Peter Hurley wrote:
>>>> Introduce tty_debug() macro to output uniform debug information for
>>>> tty core debug messages (function name and tty name).
>>> []
>>>> diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
>>> []
>>>> @@ -768,7 +768,7 @@ static void do_tty_hangup(struct work_struct *work)
>>>>  void tty_hangup(struct tty_struct *tty)
>>>>  {
>>>>  #ifdef TTY_DEBUG_HANGUP
>>>> -	printk(KERN_DEBUG "%s hangup...\n", tty_name(tty));
>>>> +	tty_debug(tty, "\n");
>>>
>>> Why drop the "hangup..." ?
>>
>> tty_debug() prints the function name; in this case, tty_hangup().
> 
> maybe that #ifdef/#endif block could/should be removed

The #ifdef/#endif block is removed in the follow-on patch 3/7;
replaced with tty_debug_hangup().

> and the function tracer used to track this instead.

One of the advantages of the single macro site of tty_debug is that
I can blow in trace_printk() instead when necessary. But still leave
mainline as printk's.

Regards,
Peter Hurley

Re: [PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Greg Kroah-Hartman]

On Sun, Jul 12, 2015 at 10:49:08PM -0400, Peter Hurley wrote:
> Introduce tty_debug() macro to output uniform debug information for
> tty core debug messages (function name and tty name).
> 
> Note: printk(KERN_DEBUG) is retained here over pr_debug() since
> messages can be enabled in non-DEBUG builds.

But pr_debug() is the "standard" way to enable/disable debugging
messages, so I'd really like to see that be used here.

Even better, this is a tty device, so it should be using dev_dbg(),
which gives us tons of good information built-in for the tty and can
properly be parsed by userspace tools to know exactly what device caused
what message at what point in time.

So I'll take this for now, but moving it to use dev_dbg() would be best
eventually.

thanks,

greg k-h

Re: [PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Peter Hurley]

On 07/23/2015 09:35 PM, Greg Kroah-Hartman wrote:
> On Sun, Jul 12, 2015 at 10:49:08PM -0400, Peter Hurley wrote:
>> Introduce tty_debug() macro to output uniform debug information for
>> tty core debug messages (function name and tty name).
>>
>> Note: printk(KERN_DEBUG) is retained here over pr_debug() since
>> messages can be enabled in non-DEBUG builds.
> 
> But pr_debug() is the "standard" way to enable/disable debugging
> messages, so I'd really like to see that be used here.

Ok, I can do that; I'll roll Joe's suggestions in at that time.

> Even better, this is a tty device, so it should be using dev_dbg(),
> which gives us tons of good information built-in for the tty and can
> properly be parsed by userspace tools to know exactly what device caused
> what message at what point in time.
> 
> So I'll take this for now, but moving it to use dev_dbg() would be best
> eventually.

The issue with using dev_dbg is that (SysV) ptys are not devices. However,
if you'd prefer, I could rework this macro to format output like dev_dbg;
ie., <driver> <tty name>: <fmt>

Regards,
Peter Hurley

Re: [PATCH 2/7] tty: core: Add tty_debug() for printk(KERN_DEBUG) messages

[Greg Kroah-Hartman]

On Wed, Aug 05, 2015 at 02:33:37PM -0400, Peter Hurley wrote:
> On 07/23/2015 09:35 PM, Greg Kroah-Hartman wrote:
> > On Sun, Jul 12, 2015 at 10:49:08PM -0400, Peter Hurley wrote:
> >> Introduce tty_debug() macro to output uniform debug information for
> >> tty core debug messages (function name and tty name).
> >>
> >> Note: printk(KERN_DEBUG) is retained here over pr_debug() since
> >> messages can be enabled in non-DEBUG builds.
> > 
> > But pr_debug() is the "standard" way to enable/disable debugging
> > messages, so I'd really like to see that be used here.
> 
> Ok, I can do that; I'll roll Joe's suggestions in at that time.
> 
> > Even better, this is a tty device, so it should be using dev_dbg(),
> > which gives us tons of good information built-in for the tty and can
> > properly be parsed by userspace tools to know exactly what device caused
> > what message at what point in time.
> > 
> > So I'll take this for now, but moving it to use dev_dbg() would be best
> > eventually.
> 
> The issue with using dev_dbg is that (SysV) ptys are not devices.

True :(

> However,
> if you'd prefer, I could rework this macro to format output like dev_dbg;
> ie., <driver> <tty name>: <fmt>

That would be good, as that's what userspace is expecting the messages
to look like.

thanks,

greg k-h