staging: fwserial: Use normal logging styles

Logging messages without newline termination are subject
to interleaving by other messages.

Avoid this by adding newlines to each message.

Neaten fwtty_<level> logging macros.
Convert driver_err to pr_err.
Add #define pr_fmt to prefix those messages.
Remove now unused driver_err macro.
Signed-off-by: Joe Perches <joe@perches.com>
Cc: Peter Hurley <peter@hurleysoftware.com>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

drivers/staging/fwserial/fwserial.c

@@ -18,6 +18,8 @@
  * Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
  */
 
+#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
+
 #include <linux/sched.h>
 #include <linux/slab.h>
 #include <linux/device.h>
@@ -101,13 +103,16 @@ struct fwtty_transaction {
 };
 
 #define to_device(a, b)			(a->b)
-#define fwtty_err(p, s, v...)		dev_err(to_device(p, device), s, ##v)
-#define fwtty_info(p, s, v...)		dev_info(to_device(p, device), s, ##v)
-#define fwtty_notice(p, s, v...)	dev_notice(to_device(p, device), s, ##v)
-#define fwtty_dbg(p, s, v...)		\
-		dev_dbg(to_device(p, device), "%s: " s, __func__, ##v)
-#define fwtty_err_ratelimited(p, s, v...) \
-		dev_err_ratelimited(to_device(p, device), s, ##v)
+#define fwtty_err(p, fmt, ...)						\
+	dev_err(to_device(p, device), fmt, ##__VA_ARGS__)
+#define fwtty_info(p, fmt, ...)						\
+	dev_info(to_device(p, device), fmt, ##__VA_ARGS__)
+#define fwtty_notice(p, fmt, ...)					\
+	dev_notice(to_device(p, device), fmt, ##__VA_ARGS__)
+#define fwtty_dbg(p, fmt, ...)						\
+	dev_dbg(to_device(p, device), "%s: " fmt, __func__, ##__VA_ARGS__)
+#define fwtty_err_ratelimited(p, fmt, ...)				\
+	dev_err_ratelimited(to_device(p, device), fmt, ##__VA_ARGS__)
 
 #ifdef DEBUG
 static inline void debug_short_write(struct fwtty_port *port, int c, int n)
@@ -118,7 +123,7 @@ static inline void debug_short_write(struct fwtty_port *port, int c, int n)
 		spin_lock_bh(&port->lock);
 		avail = dma_fifo_avail(&port->tx_fifo);
 		spin_unlock_bh(&port->lock);
-		fwtty_dbg(port, "short write: avail:%d req:%d wrote:%d",
+		fwtty_dbg(port, "short write: avail:%d req:%d wrote:%d\n",
 			  avail, c, n);
 	}
 }
@@ -197,22 +202,22 @@ static void fwtty_log_tx_error(struct fwtty_port *port, int rcode)
 {
 	switch (rcode) {
 	case RCODE_SEND_ERROR:
-		fwtty_err_ratelimited(port, "card busy");
+		fwtty_err_ratelimited(port, "card busy\n");
 		break;
 	case RCODE_ADDRESS_ERROR:
-		fwtty_err_ratelimited(port, "bad unit addr or write length");
+		fwtty_err_ratelimited(port, "bad unit addr or write length\n");
 		break;
 	case RCODE_DATA_ERROR:
-		fwtty_err_ratelimited(port, "failed rx");
+		fwtty_err_ratelimited(port, "failed rx\n");
 		break;
 	case RCODE_NO_ACK:
-		fwtty_err_ratelimited(port, "missing ack");
+		fwtty_err_ratelimited(port, "missing ack\n");
 		break;
 	case RCODE_BUSY:
-		fwtty_err_ratelimited(port, "remote busy");
+		fwtty_err_ratelimited(port, "remote busy\n");
 		break;
 	default:
-		fwtty_err_ratelimited(port, "failed tx: %d", rcode);
+		fwtty_err_ratelimited(port, "failed tx: %d\n", rcode);
 	}
 }
 
@@ -287,7 +292,7 @@ static void __fwtty_restart_tx(struct fwtty_port *port)
 		schedule_delayed_work(&port->drain, 0);
 	avail = dma_fifo_avail(&port->tx_fifo);
 
-	fwtty_dbg(port, "fifo len: %d avail: %d", len, avail);
+	fwtty_dbg(port, "fifo len: %d avail: %d\n", len, avail);
 }
 
 static void fwtty_restart_tx(struct fwtty_port *port)
@@ -323,7 +328,7 @@ static void fwtty_update_port_status(struct fwtty_port *port, unsigned status)
 	if (delta & TIOCM_CTS)
 		++port->icount.cts;
 
-	fwtty_dbg(port, "status: %x delta: %x", status, delta);
+	fwtty_dbg(port, "status: %x delta: %x\n", status, delta);
 
 	if (delta & TIOCM_CAR) {
 		tty = tty_port_tty_get(&port->port);
@@ -509,7 +514,7 @@ static void fwtty_emit_breaks(struct work_struct *work)
 	n = (elapsed * port->cps) / HZ + 1;
 	port->break_last = now;
 
-	fwtty_dbg(port, "sending %d brks", n);
+	fwtty_dbg(port, "sending %d brks\n", n);
 
 	while (n) {
 		t = min(n, 16);
@@ -570,7 +575,7 @@ static int fwtty_buffer_rx(struct fwtty_port *port, unsigned char *d, size_t n)
 	size_t size = (n + sizeof(struct buffered_rx) + 0xFF) & ~0xFF;
 
 	if (port->buffered + n > HIGH_WATERMARK) {
-		fwtty_err_ratelimited(port, "overflowed rx buffer: buffered: %d new: %zu wtrmk: %d",
+		fwtty_err_ratelimited(port, "overflowed rx buffer: buffered: %d new: %zu wtrmk: %d\n",
 				      port->buffered, n, HIGH_WATERMARK);
 		return 0;
 	}
@@ -599,7 +604,7 @@ static int fwtty_rx(struct fwtty_port *port, unsigned char *data, size_t len)
 	unsigned lsr;
 	int err = 0;
 
-	fwtty_dbg(port, "%d", n);
+	fwtty_dbg(port, "%d\n", n);
 	profile_size_distrib(port->stats.reads, n);
 
 	if (port->write_only) {
@@ -689,7 +694,7 @@ static void fwtty_port_handler(struct fw_card *card,
 	rcu_read_unlock();
 	if (!peer || peer != rcu_access_pointer(port->peer)) {
 		rcode = RCODE_ADDRESS_ERROR;
-		fwtty_err_ratelimited(port, "ignoring unauthenticated data");
+		fwtty_err_ratelimited(port, "ignoring unauthenticated data\n");
 		goto respond;
 	}
 
@@ -746,7 +751,7 @@ static void fwtty_tx_complete(struct fw_card *card, int rcode,
 	struct fwtty_port *port = txn->port;
 	int len;
 
-	fwtty_dbg(port, "rcode: %d", rcode);
+	fwtty_dbg(port, "rcode: %d\n", rcode);
 
 	switch (rcode) {
 	case RCODE_COMPLETE:
@@ -809,7 +814,7 @@ static int fwtty_tx(struct fwtty_port *port, bool drain)
 		n = dma_fifo_out_pend(&port->tx_fifo, &txn->dma_pended);
 		spin_unlock_bh(&port->lock);
 
-		fwtty_dbg(port, "out: %u rem: %d", txn->dma_pended.len, n);
+		fwtty_dbg(port, "out: %u rem: %d\n", txn->dma_pended.len, n);
 
 		if (n < 0) {
 			kmem_cache_free(fwtty_txn_cache, txn);
@@ -819,7 +824,8 @@ static int fwtty_tx(struct fwtty_port *port, bool drain)
 				profile_size_distrib(port->stats.txns, 0);
 			else {
 				++port->stats.fifo_errs;
-				fwtty_err_ratelimited(port, "fifo err: %d", n);
+				fwtty_err_ratelimited(port, "fifo err: %d\n",
+						      n);
 			}
 			break;
 		}
@@ -877,7 +883,7 @@ static void fwtty_write_xchar(struct fwtty_port *port, char ch)
 
 	++port->stats.xchars;
 
-	fwtty_dbg(port, "%02x", ch);
+	fwtty_dbg(port, "%02x\n", ch);
 
 	rcu_read_lock();
 	peer = rcu_dereference(port->peer);
@@ -964,7 +970,7 @@ static void fwtty_port_dtr_rts(struct tty_port *tty_port, int on)
 {
 	struct fwtty_port *port = to_port(tty_port, port);
 
-	fwtty_dbg(port, "on/off: %d", on);
+	fwtty_dbg(port, "on/off: %d\n", on);
 
 	spin_lock_bh(&port->lock);
 	/* Don't change carrier state if this is a console */
@@ -992,7 +998,7 @@ static int fwtty_port_carrier_raised(struct tty_port *tty_port)
 
 	rc = (port->mstatus & TIOCM_CAR);
 
-	fwtty_dbg(port, "%d", rc);
+	fwtty_dbg(port, "%d\n", rc);
 
 	return rc;
 }
@@ -1177,7 +1183,7 @@ static int fwtty_write(struct tty_struct *tty, const unsigned char *buf, int c)
 	struct fwtty_port *port = tty->driver_data;
 	int n, len;
 
-	fwtty_dbg(port, "%d", c);
+	fwtty_dbg(port, "%d\n", c);
 	profile_size_distrib(port->stats.writes, c);
 
 	spin_lock_bh(&port->lock);
@@ -1204,7 +1210,7 @@ static int fwtty_write_room(struct tty_struct *tty)
 	n = dma_fifo_avail(&port->tx_fifo);
 	spin_unlock_bh(&port->lock);
 
-	fwtty_dbg(port, "%d", n);
+	fwtty_dbg(port, "%d\n", n);
 
 	return n;
 }
@@ -1218,7 +1224,7 @@ static int fwtty_chars_in_buffer(struct tty_struct *tty)
 	n = dma_fifo_level(&port->tx_fifo);
 	spin_unlock_bh(&port->lock);
 
-	fwtty_dbg(port, "%d", n);
+	fwtty_dbg(port, "%d\n", n);
 
 	return n;
 }
@@ -1227,7 +1233,7 @@ static void fwtty_send_xchar(struct tty_struct *tty, char ch)
 {
 	struct fwtty_port *port = tty->driver_data;
 
-	fwtty_dbg(port, "%02x", ch);
+	fwtty_dbg(port, "%02x\n", ch);
 
 	fwtty_write_xchar(port, ch);
 }
@@ -1254,7 +1260,7 @@ static void fwtty_unthrottle(struct tty_struct *tty)
 {
 	struct fwtty_port *port = tty->driver_data;
 
-	fwtty_dbg(port, "CRTSCTS: %d", (C_CRTSCTS(tty) != 0));
+	fwtty_dbg(port, "CRTSCTS: %d\n", (C_CRTSCTS(tty) != 0));
 
 	profile_fifo_avail(port, port->stats.unthrottle);
 
@@ -1409,7 +1415,7 @@ static int fwtty_break_ctl(struct tty_struct *tty, int state)
 	struct fwtty_port *port = tty->driver_data;
 	long ret;
 
-	fwtty_dbg(port, "%d", state);
+	fwtty_dbg(port, "%d\n", state);
 
 	if (state == -1) {
 		set_bit(STOP_TX, &port->flags);
@@ -1446,7 +1452,7 @@ static int fwtty_tiocmget(struct tty_struct *tty)
 	tiocm = (port->mctrl & MCTRL_MASK) | (port->mstatus & ~MCTRL_MASK);
 	spin_unlock_bh(&port->lock);
 
-	fwtty_dbg(port, "%x", tiocm);
+	fwtty_dbg(port, "%x\n", tiocm);
 
 	return tiocm;
 }
@@ -1455,7 +1461,7 @@ static int fwtty_tiocmset(struct tty_struct *tty, unsigned set, unsigned clear)
 {
 	struct fwtty_port *port = tty->driver_data;
 
-	fwtty_dbg(port, "set: %x clear: %x", set, clear);
+	fwtty_dbg(port, "set: %x clear: %x\n", set, clear);
 
 	/* TODO: simulate loopback if TIOCM_LOOP set */
 
@@ -1775,7 +1781,7 @@ static void fwserial_virt_plug_complete(struct fwtty_peer *peer,
 	if (port->port.console && port->fwcon_ops->notify != NULL)
 		(*port->fwcon_ops->notify)(FWCON_NOTIFY_ATTACH, port->con_data);
 
-	fwtty_info(&peer->unit, "peer (guid:%016llx) connected on %s",
+	fwtty_info(&peer->unit, "peer (guid:%016llx) connected on %s\n",
 		   (unsigned long long)peer->guid, dev_name(port->device));
 }
 
@@ -1797,7 +1803,7 @@ static inline int fwserial_send_mgmt_sync(struct fwtty_peer *peer,
 					   pkt, be16_to_cpu(pkt->hdr.len));
 		if (rcode == RCODE_BUSY || rcode == RCODE_SEND_ERROR ||
 		    rcode == RCODE_GENERATION) {
-			fwtty_dbg(&peer->unit, "mgmt write error: %d", rcode);
+			fwtty_dbg(&peer->unit, "mgmt write error: %d\n", rcode);
 			continue;
 		} else
 			break;
@@ -1918,7 +1924,7 @@ static int fwserial_connect_peer(struct fwtty_peer *peer)
 
 	port = fwserial_find_port(peer);
 	if (!port) {
-		fwtty_err(&peer->unit, "avail ports in use");
+		fwtty_err(&peer->unit, "avail ports in use\n");
 		err = -EBUSY;
 		goto free_pkt;
 	}
@@ -2056,7 +2062,7 @@ static struct fwtty_peer *__fwserial_peer_by_node_id(struct fw_card *card,
 		 * has created its remote unit device before this driver has
 		 * been probed for any unit devices...
 		 */
-		fwtty_err(card, "unknown card (guid %016llx)",
+		fwtty_err(card, "unknown card (guid %016llx)\n",
 			  (unsigned long long) card->guid);
 		return NULL;
 	}
@@ -2084,8 +2090,8 @@ static void __dump_peer_list(struct fw_card *card)
 	list_for_each_entry_rcu(peer, &serial->peer_list, list) {
 		int g = peer->generation;
 		smp_rmb();
-		fwtty_dbg(card, "peer(%d:%x) guid: %016llx\n", g,
-			  peer->node_id, (unsigned long long) peer->guid);
+		fwtty_dbg(card, "peer(%d:%x) guid: %016llx\n",
+			  g, peer->node_id, (unsigned long long) peer->guid);
 	}
 }
 #else
@@ -2173,7 +2179,7 @@ static int fwserial_add_peer(struct fw_serial *serial, struct fw_unit *unit)
 	peer->serial = serial;
 	list_add_rcu(&peer->list, &serial->peer_list);
 
-	fwtty_info(&peer->unit, "peer added (guid:%016llx)",
+	fwtty_info(&peer->unit, "peer added (guid:%016llx)\n",
 		   (unsigned long long)peer->guid);
 
 	/* identify the local unit & virt cable to loopback port */
@@ -2236,7 +2242,7 @@ static void fwserial_remove_peer(struct fwtty_peer *peer)
 
 	list_del_rcu(&peer->list);
 
-	fwtty_info(&peer->unit, "peer removed (guid:%016llx)",
+	fwtty_info(&peer->unit, "peer removed (guid:%016llx)\n",
 		   (unsigned long long)peer->guid);
 
 	spin_unlock_bh(&peer->lock);
@@ -2324,7 +2330,7 @@ static int fwserial_create(struct fw_unit *unit)
 
 	err = fwtty_ports_add(serial);
 	if (err) {
-		fwtty_err(&unit, "no space in port table");
+		fwtty_err(&unit, "no space in port table\n");
 		goto free_ports;
 	}
 
@@ -2335,7 +2341,8 @@ static int fwserial_create(struct fw_unit *unit)
 						   card->device);
 		if (IS_ERR(tty_dev)) {
 			err = PTR_ERR(tty_dev);
-			fwtty_err(&unit, "register tty device error (%d)", err);
+			fwtty_err(&unit, "register tty device error (%d)\n",
+				  err);
 			goto unregister_ttys;
 		}
 
@@ -2352,7 +2359,8 @@ static int fwserial_create(struct fw_unit *unit)
 						    card->device);
 		if (IS_ERR(loop_dev)) {
 			err = PTR_ERR(loop_dev);
-			fwtty_err(&unit, "create loop device failed (%d)", err);
+			fwtty_err(&unit, "create loop device failed (%d)\n",
+				  err);
 			goto unregister_ttys;
 		}
 		serial->ports[j]->device = loop_dev;
@@ -2372,14 +2380,14 @@ static int fwserial_create(struct fw_unit *unit)
 
 	list_add_rcu(&serial->list, &fwserial_list);
 
-	fwtty_notice(&unit, "TTY over FireWire on device %s (guid %016llx)",
+	fwtty_notice(&unit, "TTY over FireWire on device %s (guid %016llx)\n",
 		     dev_name(card->device), (unsigned long long) card->guid);
 
 	err = fwserial_add_peer(serial, unit);
 	if (!err)
 		return 0;
 
-	fwtty_err(&unit, "unable to add peer unit device (%d)", err);
+	fwtty_err(&unit, "unable to add peer unit device (%d)\n", err);
 
 	/* fall-through to error processing */
 	debugfs_remove_recursive(serial->debugfs);
@@ -2621,7 +2629,7 @@ static void fwserial_handle_plug_req(struct work_struct *work)
 	switch (peer->state) {
 	case FWPS_NOT_ATTACHED:
 		if (!port) {
-			fwtty_err(&peer->unit, "no more ports avail");
+			fwtty_err(&peer->unit, "no more ports avail\n");
 			fill_plug_rsp_nack(pkt);
 		} else {
 			peer->port = port;
@@ -2663,7 +2671,7 @@ static void fwserial_handle_plug_req(struct work_struct *work)
 			fwtty_write_port_status(tmp);
 			spin_lock_bh(&peer->lock);
 		} else {
-			fwtty_err(&peer->unit, "PLUG_RSP error (%d)", rcode);
+			fwtty_err(&peer->unit, "PLUG_RSP error (%d)\n", rcode);
 			port = peer_revert_state(peer);
 		}
 	}
@@ -2715,7 +2723,8 @@ static void fwserial_handle_unplug_req(struct work_struct *work)
 	spin_lock_bh(&peer->lock);
 	if (peer->state == FWPS_UNPLUG_RESPONDING) {
 		if (rcode != RCODE_COMPLETE)
-			fwtty_err(&peer->unit, "UNPLUG_RSP error (%d)", rcode);
+			fwtty_err(&peer->unit, "UNPLUG_RSP error (%d)\n",
+				  rcode);
 		port = peer_revert_state(peer);
 	}
 cleanup:
@@ -2750,19 +2759,19 @@ static int fwserial_parse_mgmt_write(struct fwtty_peer *peer,
 		 * already removed from the bus -- and the removal was
 		 * processed before we rec'd this transaction
 		 */
-		fwtty_err(&peer->unit, "peer already removed");
+		fwtty_err(&peer->unit, "peer already removed\n");
 		spin_unlock_bh(&peer->lock);
 		return RCODE_ADDRESS_ERROR;
 	}
 
 	rcode = RCODE_COMPLETE;
 
-	fwtty_dbg(&peer->unit, "mgmt: hdr.code: %04hx", pkt->hdr.code);
+	fwtty_dbg(&peer->unit, "mgmt: hdr.code: %04hx\n", pkt->hdr.code);
 
 	switch (be16_to_cpu(pkt->hdr.code) & FWSC_CODE_MASK) {
 	case FWSC_VIRT_CABLE_PLUG:
 		if (work_pending(&peer->work)) {
-			fwtty_err(&peer->unit, "plug req: busy");
+			fwtty_err(&peer->unit, "plug req: busy\n");
 			rcode = RCODE_CONFLICT_ERROR;
 
 		} else {
@@ -2777,7 +2786,7 @@ static int fwserial_parse_mgmt_write(struct fwtty_peer *peer,
 			rcode = RCODE_CONFLICT_ERROR;
 
 		} else if (be16_to_cpu(pkt->hdr.code) & FWSC_RSP_NACK) {
-			fwtty_notice(&peer->unit, "NACK plug rsp");
+			fwtty_notice(&peer->unit, "NACK plug rsp\n");
 			port = peer_revert_state(peer);
 
 		} else {
@@ -2793,7 +2802,7 @@ static int fwserial_parse_mgmt_write(struct fwtty_peer *peer,
 
 	case FWSC_VIRT_CABLE_UNPLUG:
 		if (work_pending(&peer->work)) {
-			fwtty_err(&peer->unit, "unplug req: busy");
+			fwtty_err(&peer->unit, "unplug req: busy\n");
 			rcode = RCODE_CONFLICT_ERROR;
 		} else {
 			PREPARE_WORK(&peer->work, fwserial_handle_unplug_req);
@@ -2806,14 +2815,14 @@ static int fwserial_parse_mgmt_write(struct fwtty_peer *peer,
 			rcode = RCODE_CONFLICT_ERROR;
 		else {
 			if (be16_to_cpu(pkt->hdr.code) & FWSC_RSP_NACK)
-				fwtty_notice(&peer->unit, "NACK unplug?");
+				fwtty_notice(&peer->unit, "NACK unplug?\n");
 			port = peer_revert_state(peer);
 			reset = true;
 		}
 		break;
 
 	default:
-		fwtty_err(&peer->unit, "unknown mgmt code %d",
+		fwtty_err(&peer->unit, "unknown mgmt code %d\n",
 			  be16_to_cpu(pkt->hdr.code));
 		rcode = RCODE_DATA_ERROR;
 	}
@@ -2847,7 +2856,7 @@ static void fwserial_mgmt_handler(struct fw_card *card,
 	rcu_read_lock();
 	peer = __fwserial_peer_by_node_id(card, generation, source);
 	if (!peer) {
-		fwtty_dbg(card, "peer(%d:%x) not found", generation, source);
+		fwtty_dbg(card, "peer(%d:%x) not found\n", generation, source);
 		__dump_peer_list(card);
 		rcode = RCODE_CONFLICT_ERROR;
 
@@ -2897,7 +2906,7 @@ static int __init fwserial_init(void)
 
 	err = tty_register_driver(fwtty_driver);
 	if (err) {
-		driver_err("register tty driver failed (%d)", err);
+		pr_err("register tty driver failed (%d)\n", err);
 		goto put_tty;
 	}
 
@@ -2922,7 +2931,7 @@ static int __init fwserial_init(void)
 
 		err = tty_register_driver(fwloop_driver);
 		if (err) {
-			driver_err("register loop driver failed (%d)", err);
+			pr_err("register loop driver failed (%d)\n", err);
 			goto put_loop;
 		}
 	}
@@ -2948,7 +2957,7 @@ static int __init fwserial_init(void)
 	err = fw_core_add_address_handler(&fwserial_mgmt_addr_handler,
 					  &fwserial_mgmt_addr_region);
 	if (err) {
-		driver_err("add management handler failed (%d)", err);
+		pr_err("add management handler failed (%d)\n", err);
 		goto destroy_cache;
 	}
 
@@ -2956,13 +2965,13 @@ static int __init fwserial_init(void)
 		FW_UNIT_ADDRESS(fwserial_mgmt_addr_handler.offset);
 	err = fw_core_add_descriptor(&fwserial_unit_directory);
 	if (err) {
-		driver_err("add unit descriptor failed (%d)", err);
+		pr_err("add unit descriptor failed (%d)\n", err);
 		goto remove_handler;
 	}
 
 	err = driver_register(&fwserial_driver.driver);
 	if (err) {
-		driver_err("register fwserial driver failed (%d)", err);
+		pr_err("register fwserial driver failed (%d)\n", err);
 		goto remove_descriptor;
 	}
 

drivers/staging/fwserial/fwserial.h

@@ -356,8 +356,6 @@ static const char loop_dev_name[] = "fwloop";
 
 extern struct tty_driver *fwtty_driver;
 
-#define driver_err(s, v...)	pr_err(KBUILD_MODNAME ": " s, ##v)
-
 struct fwtty_port *fwtty_port_get(unsigned index);
 void fwtty_port_put(struct fwtty_port *port);