Discussion:
[PATCH 1/2] fs: merge I/O error prints into one line
(too old to reply)
Robert Elliott
2014-08-27 15:51:59 UTC
Permalink
Raw Message
buffer.c uses two printk calls to print these messages:
[67353.422338] Buffer I/O error on device sdr, logical block 212868488
[67353.422338] lost page write due to I/O error on sdr

In a busy system, they may be interleaved with other prints,
losing the context for the second message. Merge them into
one line with one printk call so the prints are atomic.

Also, differentiate between async page writes, sync page writes, and
async page reads.

Also, shorten "device" to "dev" to match the block layer prints:
[67353.467906] blk_update_request: critical target error, dev sdr, sector
1707107328

Also, use %llu rather than %Lu.

Resulting prints look like:
[ 1356.437006] blk_update_request: critical target error, dev sdr, sector 1719693992
[ 1361.383522] quiet_error: 659876 callbacks suppressed
[ 1361.385816] Buffer I/O error on dev sdr, logical block 256902912, lost async page write
[ 1361.385819] Buffer I/O error on dev sdr, logical block 256903644, lost async page write

Signed-off-by: Robert Elliott <***@hp.com>
Reviewed-by: Webb Scales <***@hp.com>
---
fs/buffer.c | 27 ++++++++-------------------
1 files changed, 8 insertions(+), 19 deletions(-)

diff --git a/fs/buffer.c b/fs/buffer.c
index 8f05111..c6cb0ee 100644
--- a/fs/buffer.c
+++ b/fs/buffer.c
@@ -137,12 +137,12 @@ static int quiet_error(struct buffer_head *bh)
}


-static void buffer_io_error(struct buffer_head *bh)
+static void buffer_io_error(struct buffer_head *bh, char *msg)
{
char b[BDEVNAME_SIZE];
- printk(KERN_ERR "Buffer I/O error on device %s, logical block %Lu\n",
+ printk(KERN_ERR "Buffer I/O error on dev %s, logical block %llu%s\n",
bdevname(bh->b_bdev, b),
- (unsigned long long)bh->b_blocknr);
+ (unsigned long long)bh->b_blocknr, msg);
}

/*
@@ -177,17 +177,11 @@ EXPORT_SYMBOL(end_buffer_read_sync);

void end_buffer_write_sync(struct buffer_head *bh, int uptodate)
{
- char b[BDEVNAME_SIZE];
-
if (uptodate) {
set_buffer_uptodate(bh);
} else {
- if (!quiet_error(bh)) {
- buffer_io_error(bh);
- printk(KERN_WARNING "lost page write due to "
- "I/O error on %s\n",
- bdevname(bh->b_bdev, b));
- }
+ if (!quiet_error(bh))
+ buffer_io_error(bh, ", lost sync page write");
set_buffer_write_io_error(bh);
clear_buffer_uptodate(bh);
}
@@ -305,7 +299,7 @@ static void end_buffer_async_read(struct buffer_head *bh, int uptodate)
} else {
clear_buffer_uptodate(bh);
if (!quiet_error(bh))
- buffer_io_error(bh);
+ buffer_io_error(bh, ", async page read");
SetPageError(page);
}

@@ -353,7 +347,6 @@ still_busy:
*/
void end_buffer_async_write(struct buffer_head *bh, int uptodate)
{
- char b[BDEVNAME_SIZE];
unsigned long flags;
struct buffer_head *first;
struct buffer_head *tmp;
@@ -365,12 +358,8 @@ void end_buffer_async_write(struct buffer_head *bh, int uptodate)
if (uptodate) {
set_buffer_uptodate(bh);
} else {
- if (!quiet_error(bh)) {
- buffer_io_error(bh);
- printk(KERN_WARNING "lost page write due to "
- "I/O error on %s\n",
- bdevname(bh->b_bdev, b));
- }
+ if (!quiet_error(bh))
+ buffer_io_error(bh, ", lost async page write");
set_bit(AS_EIO, &page->mapping->flags);
set_buffer_write_io_error(bh);
clear_buffer_uptodate(bh);

--
To unsubscribe from this list: send the line "unsubscribe linux-fsdevel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Robert Elliott
2014-08-27 15:52:05 UTC
Permalink
Raw Message
When quiet_error applies rate limiting to buffer_io_error calls, what the
they apply to is unclear because the name is so generic, particularly
if the messages are interleaved with others:

[ 1936.063572] quiet_error: 664293 callbacks suppressed
[ 1936.065297] Buffer I/O error on dev sdr, logical block 257429952, lost async page write
[ 1936.067814] Buffer I/O error on dev sdr, logical block 257429953, lost async page write

Also, the function uses printk_ratelimit(), although printk.h includes a
comment advising "Please don't use... Instead use printk_ratelimited()."

Change buffer_io_error to check the BH_Quiet bit itself, drop the
printk_ratelimit call, and print using printk_ratelimited.

This makes the messages look like:

[ 387.208839] buffer_io_error: 676394 callbacks suppressed
[ 387.210693] Buffer I/O error on dev sdr, logical block 211291776, lost async page write
[ 387.213432] Buffer I/O error on dev sdr, logical block 211291777, lost async page write

Signed-off-by: Robert Elliott <***@hp.com>
Reviewed-by: Webb Scales <***@hp.com>
---
fs/buffer.c | 23 +++++++----------------
1 files changed, 7 insertions(+), 16 deletions(-)

diff --git a/fs/buffer.c b/fs/buffer.c
index c6cb0ee..3710a68 100644
--- a/fs/buffer.c
+++ b/fs/buffer.c
@@ -128,19 +128,13 @@ __clear_page_buffers(struct page *page)
page_cache_release(page);
}

-
-static int quiet_error(struct buffer_head *bh)
-{
- if (!test_bit(BH_Quiet, &bh->b_state) && printk_ratelimit())
- return 0;
- return 1;
-}
-
-
static void buffer_io_error(struct buffer_head *bh, char *msg)
{
char b[BDEVNAME_SIZE];
- printk(KERN_ERR "Buffer I/O error on dev %s, logical block %llu%s\n",
+
+ if (!test_bit(BH_Quiet, &bh->b_state))
+ printk_ratelimited(KERN_ERR
+ "Buffer I/O error on dev %s, logical block %llu%s\n",
bdevname(bh->b_bdev, b),
(unsigned long long)bh->b_blocknr, msg);
}
@@ -180,8 +174,7 @@ void end_buffer_write_sync(struct buffer_head *bh, int uptodate)
if (uptodate) {
set_buffer_uptodate(bh);
} else {
- if (!quiet_error(bh))
- buffer_io_error(bh, ", lost sync page write");
+ buffer_io_error(bh, ", lost sync page write");
set_buffer_write_io_error(bh);
clear_buffer_uptodate(bh);
}
@@ -298,8 +291,7 @@ static void end_buffer_async_read(struct buffer_head *bh, int uptodate)
set_buffer_uptodate(bh);
} else {
clear_buffer_uptodate(bh);
- if (!quiet_error(bh))
- buffer_io_error(bh, ", async page read");
+ buffer_io_error(bh, ", async page read");
SetPageError(page);
}

@@ -358,8 +350,7 @@ void end_buffer_async_write(struct buffer_head *bh, int uptodate)
if (uptodate) {
set_buffer_uptodate(bh);
} else {
- if (!quiet_error(bh))
- buffer_io_error(bh, ", lost async page write");
+ buffer_io_error(bh, ", lost async page write");
set_bit(AS_EIO, &page->mapping->flags);
set_buffer_write_io_error(bh);
clear_buffer_uptodate(bh);
r***@beardog.cce.hp.com
2014-10-20 21:43:02 UTC
Permalink
Raw Message
The following series merges I/O error prints into one
line and makes rate limited messages clearer.
---
fs: merge I/O error prints into one line
fs: clarify rate limit suppressed buffer I/O errors
fs/buffer.c | 38 +++++++++-----------------------------
1 files changed, 9 insertions(+), 29 deletions(-)
--
ping
Jens Axboe
2014-10-20 22:00:30 UTC
Permalink
Raw Message
The following series merges I/O error prints into one
line and makes rate limited messages clearer.
---
fs: merge I/O error prints into one line
fs: clarify rate limit suppressed buffer I/O errors
fs/buffer.c | 38 +++++++++-----------------------------
1 files changed, 9 insertions(+), 29 deletions(-)
--
ping
Both are in 3.18-rc1, as released yesterday.
--
Jens Axboe
Jens Axboe
2014-10-20 22:01:40 UTC
Permalink
Raw Message
Post by Jens Axboe
The following series merges I/O error prints into one
line and makes rate limited messages clearer.
---
fs: merge I/O error prints into one line
fs: clarify rate limit suppressed buffer I/O errors
fs/buffer.c | 38 +++++++++-----------------------------
1 files changed, 9 insertions(+), 29 deletions(-)
--
ping
Both are in 3.18-rc1, as released yesterday.
Ugh no, I mixed these up with the other two (related) patches. I'll add
these for a later pull this cycle.
--
Jens Axboe

--
To unsubscribe from this list: send the line "unsubscribe linux-fsdevel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Loading...