ocfs2: limit printk when journal is aborted

PATCH New Joseph Qi 3 participants 8 messages Apr 17, 2014 – Apr 22, 2014 OCFS2

Share & tools

Joseph Qi

author

2014-04-17 11:08 UTC #0 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Once JBD2_ABORT is set, ocfs2_commit_cache will fail in ocfs2_commit_thread. Then it will get into a loop with mass logs. This will meaninglessly consume a larger number of resource and may lead to system hung at last.
So limit printk in this case.

Signed-off-by Joseph Qi <[email protected]>

---
 fs/ocfs2/journal.c | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)

fs/ocfs2/journal.c +10 -2

index 44fc3e5..cfefbd1 100644
@@ -30,6 +30,7 @@
 #include <linux/kthread.h>
 #include <linux/time.h>
 #include <linux/random.h>
+#include <linux/delay.h>
 
 #include <cluster/masklog.h>

@@ -2191,8 +2192,15 @@ static int ocfs2_commit_thread(void *arg)
 					 || kthread_should_stop());
 
 		status = ocfs2_commit_cache(osb);
-		if (status < 0)
-			mlog_errno(status);
+		if (status < 0) {
+			static unsigned long abort_warn_time;
+
+			/* Warn about this once per minute */
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}
 
 		if (kthread_should_stop() && atomic_read(&journal->j_num_trans)){
 			mlog(ML_KTHREAD,

Signature · 1 line

1.8.4.3

Mark Fasheh

2014-04-17 21:01 UTC #1 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Quoted 29 lines · Joseph Qi

Once JBD2_ABORT is set, ocfs2_commit_cache will fail in ocfs2_commit_thread. Then it will get into a loop with mass logs. This will meaninglessly consume a larger number of resource and may lead to system hung at last.
So limit printk in this case.
Signed-off-by Joseph Qi <[email protected]>
---
 fs/ocfs2/journal.c | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)
fs/ocfs2/journal.c +1 -1
index 44fc3e5..cfefbd1 100644
@@ -30,6 +30,7 @@
 #include <linux/kthread.h>
 #include <linux/time.h>
 #include <linux/random.h>
+#include <linux/delay.h>
 
 #include <cluster/masklog.h>
 
@@ -2191,8 +2192,15 @@ static int ocfs2_commit_thread(void *arg)
 					 || kthread_should_stop());
 
 		status = ocfs2_commit_cache(osb);
-		if (status < 0)

fs/ocfs2/journal.c static int ocfs2_commit_thread(void *arg) · line 2203

Quoted 10 lines

fs/ocfs2/journal.c +9 -1

-			mlog_errno(status);
+		if (status < 0) {
+			static unsigned long abort_warn_time;
+
+			/* Warn about this once per minute */
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}

Why the msleep? ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?

Generally I really don't like peppering msleep() into the code where we might need to sleep - there is often a more elegant solution available.

Thanks,

	--Mark

--
Mark Fasheh

Joseph Qi

author

2014-04-18 01:02 UTC #2 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Quoted 28 lines · Mark Fasheh

Quoted 27 lines · Joseph Qi
Once JBD2_ABORT is set, ocfs2_commit_cache will fail in ocfs2_commit_thread. Then it will get into a loop with mass logs. This will meaninglessly consume a larger number of resource and may lead to system hung at last.
So limit printk in this case.
Signed-off-by Joseph Qi <[email protected]>
---
 fs/ocfs2/journal.c | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)
fs/ocfs2/journal.c +1 -0
index 44fc3e5..cfefbd1 100644
@@ -30,6 +30,7 @@
 #include <linux/kthread.h>
 #include <linux/time.h>
 #include <linux/random.h>
+#include <linux/delay.h>
 
 #include <cluster/masklog.h>
 
@@ -2191,8 +2192,15 @@ static int ocfs2_commit_thread(void *arg)
 					 || kthread_should_stop());
 

Quoted 16 lines

fs/ocfs2/journal.c static int ocfs2_commit_thread(void *arg) · line 2203
Quoted 12 lines
fs/ocfs2/journal.c +9 -2
 		status = ocfs2_commit_cache(osb);
-		if (status < 0)
-			mlog_errno(status);
+		if (status < 0) {
+			static unsigned long abort_warn_time;
+
+			/* Warn about this once per minute */
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}
Why the msleep? ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?

Since jbd2 is already aborted, commit cache is meaningless.

Quoted 10 lines

Generally I really don't like peppering msleep() into the code where we might need to sleep - there is often a more elegant solution available.
Thanks,
	--Mark
--
Mark Fasheh

Mark Fasheh

2014-04-18 02:45 UTC #3 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Quoted 45 lines · Joseph Qi

Quoted 28 lines · Mark Fasheh
Quoted 27 lines · Joseph Qi
Once JBD2_ABORT is set, ocfs2_commit_cache will fail in ocfs2_commit_thread. Then it will get into a loop with mass logs. This will meaninglessly consume a larger number of resource and may lead to system hung at last.
So limit printk in this case.
Signed-off-by Joseph Qi <[email protected]>
---
 fs/ocfs2/journal.c | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)
fs/ocfs2/journal.c +1 -0
index 44fc3e5..cfefbd1 100644
@@ -30,6 +30,7 @@
 #include <linux/kthread.h>
 #include <linux/time.h>
 #include <linux/random.h>
+#include <linux/delay.h>
 
 #include <cluster/masklog.h>
 
@@ -2191,8 +2192,15 @@ static int ocfs2_commit_thread(void *arg)
 					 || kthread_should_stop());
 
Quoted 16 lines
fs/ocfs2/journal.c static int ocfs2_commit_thread(void *arg) · line 2203
Quoted 12 lines
fs/ocfs2/journal.c +9 -2
 		status = ocfs2_commit_cache(osb);
-		if (status < 0)
-			mlog_errno(status);
+		if (status < 0) {
+			static unsigned long abort_warn_time;
+
+			/* Warn about this once per minute */
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}
Why the msleep? ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?

Quoted 1 line

Since jbd2 is already aborted, commit cache is meaningless.

I understand that, but I'm asking why the msleep and whether we can avoid that. To go back to my question:

"ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?"

Thanks,

	--Mark

--
Mark Fasheh

Joseph Qi

author

2014-04-18 09:18 UTC #4 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Quoted 48 lines · Mark Fasheh

Quoted 45 lines · Joseph Qi
Quoted 28 lines · Mark Fasheh
Quoted 27 lines · Joseph Qi
Once JBD2_ABORT is set, ocfs2_commit_cache will fail in ocfs2_commit_thread. Then it will get into a loop with mass logs. This will meaninglessly consume a larger number of resource and may lead to system hung at last.
So limit printk in this case.
Signed-off-by Joseph Qi <[email protected]>
---
 fs/ocfs2/journal.c | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)
fs/ocfs2/journal.c +1 -0
index 44fc3e5..cfefbd1 100644
@@ -30,6 +30,7 @@
 #include <linux/kthread.h>
 #include <linux/time.h>
 #include <linux/random.h>
+#include <linux/delay.h>
 
 #include <cluster/masklog.h>
 
@@ -2191,8 +2192,15 @@ static int ocfs2_commit_thread(void *arg)
 					 || kthread_should_stop());
 
Quoted 16 lines
fs/ocfs2/journal.c static int ocfs2_commit_thread(void *arg) · line 2203
Quoted 12 lines
fs/ocfs2/journal.c +9 -2
 		status = ocfs2_commit_cache(osb);
-		if (status < 0)
-			mlog_errno(status);
+		if (status < 0) {
+			static unsigned long abort_warn_time;
+
+			/* Warn about this once per minute */
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}
Why the msleep? ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?
Quoted 1 line
Since jbd2 is already aborted, commit cache is meaningless.

Quoted 8 lines

I understand that, but I'm asking why the msleep and whether we can avoid that. To go back to my question:
"ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?"
Thanks,
	--Mark

Sorry for my obscure description.
If ocfs2_commit_cache fails because of JBD2_ABORT, j_num_trans won't be cleared. Then the condition of checkpoint event still evaluates true, so it won't wait.

Quoted 6 lines

--
Mark Fasheh
.

Andrew Morton

2014-04-21 19:18 UTC #5 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Quoted 14 lines · On Fri, 18 Apr 2014 17:18:27 +0800 Joseph Qi <[email protected]> wrote:

Quoted 14 lines
Quoted 10 lines
Quoted 9 lines
Review
Quoted 5 lines
(quoted diff) +5 -0
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}
Why the msleep? ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?
Since jbd2 is already aborted, commit cache is meaningless.
I understand that, but I'm asking why the msleep and whether we can avoid that. To go back to my question:

Quoted 8 lines

Quoted 5 lines
"ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?"
Thanks,
	--Mark
Sorry for my obscure description.
If ocfs2_commit_cache fails because of JBD2_ABORT, j_num_trans won't be cleared. Then the condition of checkpoint event still evaluates true, so it won't wait.

If Mark didn't understand the reason for the msleep then nobody weill, so we need to add a comment. This?

fs/ocfs2/journal.c renamed from fs/ocfs2/journal.c~ocfs2-limit-printk-when-journal-is-aborted-fix +5 -0

@@ -2193,6 +2193,11 @@ static int ocfs2_commit_thread(void *arg
 			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
 				mlog(ML_ERROR, "status = %d, journal is "
 						"already aborted.\n", status);
+			/*
+			 * After ocfs2_commit_cache() fails, j_num_trans has a
+			 * non-zero value.  Sleep here to avoid a busy-wait
+			 * loop.
+			 */
 			msleep_interruptible(1000);
 		}

This patch seems rather hacky :( Isn't there a better solution?

Why even keep the kernel thread running after an abort?

Mark Fasheh

2014-04-21 20:51 UTC #6 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Quoted 43 lines · Andrew Morton

Quoted 14 lines · On Fri, 18 Apr 2014 17:18:27 +0800 Joseph Qi <[email protected]> wrote:
Quoted 14 lines
Quoted 10 lines
Quoted 9 lines
Review
Quoted 5 lines
(quoted diff) +5 -0
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}
Why the msleep? ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?
Since jbd2 is already aborted, commit cache is meaningless.
I understand that, but I'm asking why the msleep and whether we can avoid that. To go back to my question:
Quoted 8 lines
Quoted 5 lines
"ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?"
Thanks,
	--Mark
Sorry for my obscure description.
If ocfs2_commit_cache fails because of JBD2_ABORT, j_num_trans won't be cleared. Then the condition of checkpoint event still evaluates true, so it won't wait.
If Mark didn't understand the reason for the msleep then nobody weill, so we need to add a comment. This?
fs/ocfs2/journal.c renamed from fs/ocfs2/journal.c~ocfs2-limit-printk-when-journal-is-aborted-fix +5 -0
@@ -2193,6 +2193,11 @@ static int ocfs2_commit_thread(void *arg
 			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
 				mlog(ML_ERROR, "status = %d, journal is "
 						"already aborted.\n", status);
+			/*
+			 * After ocfs2_commit_cache() fails, j_num_trans has a
+			 * non-zero value.  Sleep here to avoid a busy-wait
+			 * loop.
+			 */
 			msleep_interruptible(1000);
 		}
 

Quoted 1 line

This patch seems rather hacky :( Isn't there a better solution?

Right, that's what I was getting at with my followup later on in the mail thread about this.

Quoted 1 line

Why even keep the kernel thread running after an abort?

The msleep is papering over the real issue. Either the thread should shut down or we need to re-evaluate usage of j_num_trans which is the condition that keeps it from sleeping (and from a quick glance it doesn't seem like j_num_trans does anything for us).

	--Mark

--
Mark Fasheh

Joseph Qi

author

2014-04-22 01:08 UTC #7 lore raw

PATCH 1/1 ocfs2: limit printk when journal is aborted

Quoted 50 lines · Mark Fasheh

Quoted 43 lines · Andrew Morton
Quoted 14 lines · On Fri, 18 Apr 2014 17:18:27 +0800 Joseph Qi <[email protected]> wrote:
Quoted 14 lines
Quoted 10 lines
Quoted 9 lines
Review
Quoted 5 lines
(quoted diff) +5 -0
+			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
+				mlog(ML_ERROR, "status = %d, journal is "
+						"already aborted.\n", status);
+			msleep_interruptible(1000);
+		}
Why the msleep? ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?
Since jbd2 is already aborted, commit cache is meaningless.
I understand that, but I'm asking why the msleep and whether we can avoid that. To go back to my question:
Quoted 8 lines
Quoted 5 lines
"ocfs2_commit_thread will wait on the checkpoint_event queue right after this anyway - is there a problem with it waiting on that?"
Thanks,
	--Mark
Sorry for my obscure description.
If ocfs2_commit_cache fails because of JBD2_ABORT, j_num_trans won't be cleared. Then the condition of checkpoint event still evaluates true, so it won't wait.
If Mark didn't understand the reason for the msleep then nobody weill, so we need to add a comment. This?
fs/ocfs2/journal.c renamed from fs/ocfs2/journal.c~ocfs2-limit-printk-when-journal-is-aborted-fix +5 -0
@@ -2193,6 +2193,11 @@ static int ocfs2_commit_thread(void *arg
 			if (printk_timed_ratelimit(&abort_warn_time, 60*HZ))
 				mlog(ML_ERROR, "status = %d, journal is "
 						"already aborted.\n", status);
+			/*
+			 * After ocfs2_commit_cache() fails, j_num_trans has a
+			 * non-zero value.  Sleep here to avoid a busy-wait
+			 * loop.
+			 */
 			msleep_interruptible(1000);
 		}
 
Quoted 1 line
This patch seems rather hacky :( Isn't there a better solution?
Right, that's what I was getting at with my followup later on in the mail thread about this.

Quoted 8 lines

Quoted 1 line
Why even keep the kernel thread running after an abort?
The msleep is papering over the real issue. Either the thread should shut down or we need to re-evaluate usage of j_num_trans which is the condition that keeps it from sleeping (and from a quick glance it doesn't seem like j_num_trans does anything for us).
	--Mark

AFAIK, the commit thread ends only if dismounting volume. Journal abort is different from journal shutdown, that's why leaves it running.

Quoted 5 lines

--
Mark Fasheh
.