UBIFS: improve debugging messaged

1. Make the I/O debugging message print the journal head number.
2. Add prints to timer functions.

Signed-off-by: Artem Bityutskiy <Artem.Bityutskiy@nokia.com>

fs/ubifs/io.c

@@ -297,6 +297,7 @@ static enum hrtimer_restart wbuf_timer_callback_nolock(struct hrtimer *timer)
 {
 	struct ubifs_wbuf *wbuf = container_of(timer, struct ubifs_wbuf, timer);
 
+	dbg_io("jhead %d", wbuf->jhead);
 	wbuf->need_sync = 1;
 	wbuf->c->need_wbuf_sync = 1;
 	ubifs_wake_up_bgt(wbuf->c);
@@ -313,6 +314,9 @@ static void new_wbuf_timer_nolock(struct ubifs_wbuf *wbuf)
 
 	if (!ktime_to_ns(wbuf->softlimit))
 		return;
+	dbg_io("set timer for jhead %d, %llu-%llu millisecs", wbuf->jhead,
+	       ktime_to_ns(wbuf->softlimit)/USEC_PER_SEC,
+	       (ktime_to_ns(wbuf->softlimit) + wbuf->delta)/USEC_PER_SEC);
 	hrtimer_start_range_ns(&wbuf->timer, wbuf->softlimit, wbuf->delta,
 			       HRTIMER_MODE_REL);
 }
@@ -349,8 +353,8 @@ int ubifs_wbuf_sync_nolock(struct ubifs_wbuf *wbuf)
 		/* Write-buffer is empty or not seeked */
 		return 0;
 
-	dbg_io("LEB %d:%d, %d bytes",
-	       wbuf->lnum, wbuf->offs, wbuf->used);
+	dbg_io("LEB %d:%d, %d bytes, jhead %d",
+	       wbuf->lnum, wbuf->offs, wbuf->used, wbuf->jhead);
 	ubifs_assert(!(c->vfs_sb->s_flags & MS_RDONLY));
 	ubifs_assert(!(wbuf->avail & 7));
 	ubifs_assert(wbuf->offs + c->min_io_size <= c->leb_size);
@@ -399,7 +403,7 @@ int ubifs_wbuf_seek_nolock(struct ubifs_wbuf *wbuf, int lnum, int offs,
 {
 	const struct ubifs_info *c = wbuf->c;
 
-	dbg_io("LEB %d:%d", lnum, offs);
+	dbg_io("LEB %d:%d, jhead %d", lnum, offs, wbuf->jhead);
 	ubifs_assert(lnum >= 0 && lnum < c->leb_cnt);
 	ubifs_assert(offs >= 0 && offs <= c->leb_size);
 	ubifs_assert(offs % c->min_io_size == 0 && !(offs & 7));
@@ -506,9 +510,9 @@ int ubifs_wbuf_write_nolock(struct ubifs_wbuf *wbuf, void *buf, int len)
 	struct ubifs_info *c = wbuf->c;
 	int err, written, n, aligned_len = ALIGN(len, 8), offs;
 
-	dbg_io("%d bytes (%s) to wbuf at LEB %d:%d", len,
-	       dbg_ntype(((struct ubifs_ch *)buf)->node_type), wbuf->lnum,
-	       wbuf->offs + wbuf->used);
+	dbg_io("%d bytes (%s) to jhead %d wbuf at LEB %d:%d", len,
+	       dbg_ntype(((struct ubifs_ch *)buf)->node_type), wbuf->jhead,
+	       wbuf->lnum, wbuf->offs + wbuf->used);
 	ubifs_assert(len > 0 && wbuf->lnum >= 0 && wbuf->lnum < c->leb_cnt);
 	ubifs_assert(wbuf->offs >= 0 && wbuf->offs % c->min_io_size == 0);
 	ubifs_assert(!(wbuf->offs & 7) && wbuf->offs <= c->leb_size);
@@ -533,8 +537,8 @@ int ubifs_wbuf_write_nolock(struct ubifs_wbuf *wbuf, void *buf, int len)
 		memcpy(wbuf->buf + wbuf->used, buf, len);
 
 		if (aligned_len == wbuf->avail) {
-			dbg_io("flush wbuf to LEB %d:%d", wbuf->lnum,
-				wbuf->offs);
+			dbg_io("flush jhead %d wbuf to LEB %d:%d",
+			       wbuf->jhead, wbuf->lnum, wbuf->offs);
 			err = ubi_leb_write(c->ubi, wbuf->lnum, wbuf->buf,
 					    wbuf->offs, c->min_io_size,
 					    wbuf->dtype);
@@ -562,7 +566,8 @@ int ubifs_wbuf_write_nolock(struct ubifs_wbuf *wbuf, void *buf, int len)
 	 * minimal I/O unit. We have to fill and flush write-buffer and switch
 	 * to the next min. I/O unit.
 	 */
-	dbg_io("flush wbuf to LEB %d:%d", wbuf->lnum, wbuf->offs);
+	dbg_io("flush jhead %d wbuf to LEB %d:%d",
+	       wbuf->jhead, wbuf->lnum, wbuf->offs);
 	memcpy(wbuf->buf + wbuf->used, buf, wbuf->avail);
 	err = ubi_leb_write(c->ubi, wbuf->lnum, wbuf->buf, wbuf->offs,
 			    c->min_io_size, wbuf->dtype);
@@ -695,7 +700,8 @@ int ubifs_read_node_wbuf(struct ubifs_wbuf *wbuf, void *buf, int type, int len,
 	int err, rlen, overlap;
 	struct ubifs_ch *ch = buf;
 
-	dbg_io("LEB %d:%d, %s, length %d", lnum, offs, dbg_ntype(type), len);
+	dbg_io("LEB %d:%d, %s, length %d, jhead %d", lnum, offs,
+	       dbg_ntype(type), len, wbuf->jhead);
 	ubifs_assert(wbuf && lnum >= 0 && lnum < c->leb_cnt && offs >= 0);
 	ubifs_assert(!(offs & 7) && offs < c->leb_size);
 	ubifs_assert(type >= 0 && type < UBIFS_NODE_TYPES_CNT);