jbd: don't wake kjournald unnecessarily

RFC PATCH In review Eric Sandeen 4 participants 20 messages Dec 18, 2012 – Jan 11, 2013 Journalling layer for block devices (JBD2)

lore

Share & tools

lore

Eric Sandeen

author

2012-12-18 17:04 UTC #0 lore raw

RFC PATCH 1/1 jbd: don't wake kjournald unnecessarily

Commit d9b0193 jbd: fix fsync() tid wraparound bug changed the logic for whether __log_start_commit() should wake up kjournald.

After backporting this to RHEL6, I had a report of a performance regression on a large benchmark, and it was narrowed down to the change above.

I did a little investigation of jbd behavior while running xfstest 013, which just does a large fsstress run, and found that we were waking up kjournald more often than before; specifically, in the case where

	target == j_commit_request == journal->j_running_transaction

It seems to me that the wakeup is not needed if we already have the right target on the commit request, so I tested with the additional condition added in the patch below; this brought performance back up to prior levels.

I also tested it with tid_t defined to a u8, to get frequent wraps. If I back out the wraparound patch, it will easily provoke the original ASSERT that prompted the prior commit. With the commit in place and the patch below, I survived running fsstress for 10 hours without problems even with a frequently-wrapping tid_t.

A couple questions remain:

With a u8 tid_t, the "else" clause from commit d9b0193 fires frequently; I really think the underlying problem is that tid_geq() etc does not properly handle wraparounds - if, say, target is 255 and j_commit_request is 0, we don't know if j_commit_request is 255 tids behind, or 1 tid ahead. I have to think about that some more, unless it's obvious to someone else.

FWIW, some people have indeed seen that else clause fire upstream, both in the case where j_commit_request is > 2^31 and the target is 0.

https://bugzilla.kernel.org/show_bug.cgi?id=46031
http://forums.debian.net/viewtopic.php?f=5&t=80741

Anyway, I think this patch helps on the "don't send extra wakeups" side of things. Does anyone see a problem with it?

If it looks ok, I'll send the same for jbd2.

Thanks,
-Eric

=============
[PATCH] jbd: don't wake kjournald unnecessarily

Don't send an extra wakeup to kjournald in the case where we already have the proper target in j_commit_request, i.e. that commit has already been requested for commit.

commit d9b0193 "jbd: fix fsync() tid wraparound bug" changed the logic leading to a wakeup, but it caused some extra wakeups which were found to lead to a measurable performance regression.

Signed-off-by Eric Sandeen <[email protected]>

---

fs/jbd/journal.c +2 -1

index a286233..81cc7ea 100644
@@ -446,7 +446,8 @@ int __log_start_commit(journal_t *journal, tid_t target)
 	 * currently running transaction (if it exists).  Otherwise,
 	 * the target tid must be an old one.
 	 */
-	if (journal->j_running_transaction &&
+	if (journal->j_commit_request != target &&
+	    journal->j_running_transaction &&
 	    journal->j_running_transaction->t_tid == target) {
 		/*
 		 * We want a new commit: OK, mark the request and wakeup the

Jan Kara

2012-12-19 01:27 UTC #1 lore raw

Quoted 6 lines · Eric Sandeen

Commit d9b0193 jbd: fix fsync() tid wraparound bug changed the logic for whether __log_start_commit() should wake up kjournald.
After backporting this to RHEL6, I had a report of a performance regression on a large benchmark, and it was narrowed down to the change above.

Strange. I wonder what really happened that those additional wakeups had
influence on performance. They should be pretty cheap.

Quoted 11 lines

I did a little investigation of jbd behavior while running xfstest 013, which just does a large fsstress run, and found that we were waking up kjournald more often than before; specifically, in the case where
	target == j_commit_request == journal->j_running_transaction
It seems to me that the wakeup is not needed if we already have the right target on the commit request, so I tested with the additional condition added in the patch below; this brought performance back up to prior levels.

Correct.

Quoted 6 lines

I also tested it with tid_t defined to a u8, to get frequent wraps. If I back out the wraparound patch, it will easily provoke the original ASSERT that prompted the prior commit. With the commit in place and the patch below, I survived running fsstress for 10 hours without problems even with a frequently-wrapping tid_t.

Thanks for throughout testing!

Quoted 8 lines

A couple questions remain:
With a u8 tid_t, the "else" clause from commit d9b0193 fires frequently; I really think the underlying problem is that tid_geq() etc does not properly handle wraparounds - if, say, target is 255 and j_commit_request is 0, we don't know if j_commit_request is 255 tids behind, or 1 tid ahead. I have to think about that some more, unless it's obvious to someone else.

Well, there's no way to handle wraps better AFAICT. Tids eventually wrap
and if someone has stored away tid of a transaction he wants committed and keeps it for a long time before using it, it can end up being anywhere before / after current j_commit_request. The hope was that it takes long enough to wrap around 32-bit tids. If this happens often in practice we may have to switch to 64-bit tids (in memory, on disk 32-bit tids are enough because of limited journal size).

Quoted 6 lines

FWIW, some people have indeed seen that else clause fire upstream, both in the case where j_commit_request is > 2^31 and the target is 0.
https://bugzilla.kernel.org/show_bug.cgi?id=46031
http://forums.debian.net/viewtopic.php?f=5&t=80741

This is actually curious. The fact that i_datasync_tid was 0 means that
either journal was not initialized during ext3_iget() or j_commit_sequence was 0 during ext3_iget() - note that j_commit_sequence is initialized to j_transaction_sequence in journal_reset()... Hum, but in a case when ext3_load_journal() calls journal_wipe() and that finds j_tail != 0, we call journal_skip_recovery(). That ends up setting j_transaction_sequence to the last transaction in the log but j_commit_sequence is left at 0. I see that explains how we could hit the warning. I think we should initialize j_commit_sequence properly also when skipping recovery and that will solve the problem.

BTW if we find j_tail == 0 in journal_wipe(), we skip setting j_transaction_sequence to the last transaction in the journal. So j_transaction_sequence ends up being 0 but j_tail_sequence is set by load_superblock() to sb->s_sequence so there's a mismatch between reality and what j_tail_sequence claims to be the oldest transaction in the log. That reminds me of the report where bogus journal replay corrupted a filesystem...

I'll fix both these issues.

Quoted 2 lines

Anyway, I think this patch helps on the "don't send extra wakeups" side of things. Does anyone see a problem with it?

The patch is fine. I'll queue it up.

Honza

Quoted 28 lines

=============
[PATCH] jbd: don't wake kjournald unnecessarily
Don't send an extra wakeup to kjournald in the case where we already have the proper target in j_commit_request, i.e. that commit has already been requested for commit.
commit d9b0193 "jbd: fix fsync() tid wraparound bug" changed the logic leading to a wakeup, but it caused some extra wakeups which were found to lead to a measurable performance regression.
Signed-off-by Eric Sandeen <[email protected]>
---
fs/jbd/journal.c +2 -1
index a286233..81cc7ea 100644
@@ -446,7 +446,8 @@ int __log_start_commit(journal_t *journal, tid_t target)
 	 * currently running transaction (if it exists).  Otherwise,
 	 * the target tid must be an old one.
 	 */
-	if (journal->j_running_transaction &&
+	if (journal->j_commit_request != target &&
+	    journal->j_running_transaction &&
 	    journal->j_running_transaction->t_tid == target) {
 		/*
 		 * We want a new commit: OK, mark the request and wakeup the

Signature · 2 lines

Jan Kara <[email protected]>
SUSE Labs, CR

Jan Kara

2012-12-19 02:05 UTC #2 lore raw

Quoted 20 lines · Jan Kara

Quoted 6 lines
With a u8 tid_t, the "else" clause from commit d9b0193 fires frequently; I really think the underlying problem is that tid_geq() etc does not properly handle wraparounds - if, say, target is 255 and j_commit_request is 0, we don't know if j_commit_request is 255 tids behind, or 1 tid ahead. I have to think about that some more, unless it's obvious to someone else.
Well, there's no way to handle wraps better AFAICT. Tids eventually wrap
and if someone has stored away tid of a transaction he wants committed and keeps it for a long time before using it, it can end up being anywhere before / after current j_commit_request. The hope was that it takes long enough to wrap around 32-bit tids. If this happens often in practice we may have to switch to 64-bit tids (in memory, on disk 32-bit tids are enough because of limited journal size).
Quoted 6 lines
FWIW, some people have indeed seen that else clause fire upstream, both in the case where j_commit_request is > 2^31 and the target is 0.
https://bugzilla.kernel.org/show_bug.cgi?id=46031
http://forums.debian.net/viewtopic.php?f=5&t=80741

Quoted 10 lines

This is actually curious. The fact that i_datasync_tid was 0 means that
either journal was not initialized during ext3_iget() or j_commit_sequence was 0 during ext3_iget() - note that j_commit_sequence is initialized to j_transaction_sequence in journal_reset()... Hum, but in a case when ext3_load_journal() calls journal_wipe() and that finds j_tail != 0, we call journal_skip_recovery(). That ends up setting j_transaction_sequence to the last transaction in the log but j_commit_sequence is left at 0. I see that explains how we could hit the warning. I think we should initialize j_commit_sequence properly also when skipping recovery and that will solve the problem.

Bah, I was wrong here. I misread ext3_journal_load(). We call
journal_load() after journal_wipe() and so j_transaction_sequence and j_commit_sequence() are set properly... But then I don't see how i_datasync_tid was zero (modulo the very unlikely event we happened to load the inode just after wrapping tids).

Honza

Signature · 2 lines

Jan Kara <[email protected]>
SUSE Labs, CR

Eric Sandeen

author

2012-12-19 03:09 UTC #3 lore raw

Quoted 7 lines · Jan Kara

Quoted 6 lines · Jan Kara
Quoted 6 lines
With a u8 tid_t, the "else" clause from commit d9b0193 fires frequently; I really think the underlying problem is that tid_geq() etc does not properly handle wraparounds - if, say, target is 255 and j_commit_request is 0, we don't know if j_commit_request is 255 tids behind, or 1 tid ahead. I have to think about that some more, unless it's obvious to someone else.

Quoted 7 lines

Quoted 7 lines
Well, there's no way to handle wraps better AFAICT. Tids eventually wrap
and if someone has stored away tid of a transaction he wants committed and keeps it for a long time before using it, it can end up being anywhere before / after current j_commit_request. The hope was that it takes long enough to wrap around 32-bit tids. If this happens often in practice we may have to switch to 64-bit tids (in memory, on disk 32-bit tids are enough because of limited journal size).

I was wondering if, since the tid_g*() functions only work if the distance is half the unsigned int space, we can force a commit at some point if j_transaction_sequence has gotten too far ahead? I'm not sure where or if that could be done...

-Eric

Jan Kara

2012-12-19 08:13 UTC #4 lore raw

Quoted 16 lines · Eric Sandeen

Quoted 7 lines · Jan Kara
Quoted 6 lines · Jan Kara
Quoted 6 lines
With a u8 tid_t, the "else" clause from commit d9b0193 fires frequently; I really think the underlying problem is that tid_geq() etc does not properly handle wraparounds - if, say, target is 255 and j_commit_request is 0, we don't know if j_commit_request is 255 tids behind, or 1 tid ahead. I have to think about that some more, unless it's obvious to someone else.
Quoted 7 lines
Quoted 7 lines
Well, there's no way to handle wraps better AFAICT. Tids eventually wrap
and if someone has stored away tid of a transaction he wants committed and keeps it for a long time before using it, it can end up being anywhere before / after current j_commit_request. The hope was that it takes long enough to wrap around 32-bit tids. If this happens often in practice we may have to switch to 64-bit tids (in memory, on disk 32-bit tids are enough because of limited journal size).

Quoted 4 lines

I was wondering if, since the tid_g*() functions only work if the distance is half the unsigned int space, we can force a commit at some point if j_transaction_sequence has gotten too far ahead? I'm not sure where or if that could be done...

I don't quiete understand. If someone stores tid = transaction->t_tid and
in two weeks calls log_start_commit(tid), I don't see how any forcing of commits could solve that tid may now look ahead of the log...

Honza

Signature · 2 lines

Jan Kara <[email protected]>
SUSE Labs, CR

Theodore Ts'o

maintainer

2012-12-19 15:37 UTC #5 lore raw

Quoted 8 lines · Jan Kara

Quoted 4 lines
I was wondering if, since the tid_g*() functions only work if the distance is half the unsigned int space, we can force a commit at some point if j_transaction_sequence has gotten too far ahead? I'm not sure where or if that could be done...
I don't quiete understand. If someone stores tid = transaction->t_tid and
in two weeks calls log_start_commit(tid), I don't see how any forcing of commits could solve that tid may now look ahead of the log...

Actually, what we can do is the reverse. Right now when we modify an inode, we stash the tid to indicate "we need to commit to at least this tid". The problem comes if we haven't modified the inode for a long time, but then later when we issue an fsync for that inode, it's after a tid wrap, so we trigger the warning.

What we could do is in cases were we aren't touching the inode note if the tid value is obviously out of date, and set it to some value which is one less than the current tid. This avoids the wrap, and in cases where we are releasing the inode and nothing else is left, it's a safe thing to do.

The downside is that doing this would incur locking overhead, and it's not clear it's worth it. Now that we understand what's going on, nothing bad is happening when the warning is triggered, so we could just remove it.

If we use a 64-bit in-memory tid, that would help avoid cases where the tid has wrapped and we get unlucky and hit the 1 in 2**32 case where we trigger a commit where one is not needed. Given that the cost of an extra commit with probably 1 in 2**32 is pretty low, it's probably not worth the overhead of using a 64-bit tid, though....

- Ted

Jan Kara

2012-12-19 17:14 UTC #6 lore raw

Quoted 27 lines · Ted Tso

Quoted 8 lines · Jan Kara
Quoted 4 lines
I was wondering if, since the tid_g*() functions only work if the distance is half the unsigned int space, we can force a commit at some point if j_transaction_sequence has gotten too far ahead? I'm not sure where or if that could be done...
I don't quiete understand. If someone stores tid = transaction->t_tid and
in two weeks calls log_start_commit(tid), I don't see how any forcing of commits could solve that tid may now look ahead of the log...
Actually, what we can do is the reverse. Right now when we modify an inode, we stash the tid to indicate "we need to commit to at least this tid". The problem comes if we haven't modified the inode for a long time, but then later when we issue an fsync for that inode, it's after a tid wrap, so we trigger the warning.
What we could do is in cases were we aren't touching the inode note if the tid value is obviously out of date, and set it to some value which is one less than the current tid. This avoids the wrap, and in cases where we are releasing the inode and nothing else is left, it's a safe thing to do.
The downside is that doing this would incur locking overhead, and it's not clear it's worth it. Now that we understand what's going on, nothing bad is happening when the warning is triggered, so we could just remove it.

Quoted 5 lines

If we use a 64-bit in-memory tid, that would help avoid cases where the tid has wrapped and we get unlucky and hit the 1 in 2**32 case where we trigger a commit where one is not needed. Given that the cost of an extra commit with probably 1 in 2**32 is pretty low, it's probably not worth the overhead of using a 64-bit tid, though....

I agree. Just I'm still somewhat puzzled by those two reports pointed to
by Eric. In both cases stored tids were 0 and I cannot see how that happens (well how it could happen in a reasonably likely way).

Honza

Signature · 2 lines

Jan Kara <[email protected]>
SUSE Labs, CR

Theodore Ts'o

maintainer

2012-12-19 20:27 UTC #7 lore raw

Quoted 3 lines · Jan Kara

I agree. Just I'm still somewhat puzzled by those two reports pointed to
by Eric. In both cases stored tids were 0 and I cannot see how that happens (well how it could happen in a reasonably likely way).

I'm also really puzzled about how Eric's patch makes a 10% different on the AIM7 benchmark; as you've pointed out, that will just cause an extra wakeup of the jbd/jbd2 thread, which should then quickly check and decide to go back to sleep.

- Ted

Eric Sandeen

2012-12-19 21:20 UTC #8 lore raw

Quoted 9 lines · Theodore Ts'o

Quoted 3 lines · Jan Kara
I agree. Just I'm still somewhat puzzled by those two reports pointed to
by Eric. In both cases stored tids were 0 and I cannot see how that happens (well how it could happen in a reasonably likely way).
I'm also really puzzled about how Eric's patch makes a 10% different on the AIM7 benchmark; as you've pointed out, that will just cause an extra wakeup of the jbd/jbd2 thread, which should then quickly check and decide to go back to sleep.

TBH I'm puzzled too, but that's what the perf guys tell me...

Eric

Quoted 1 line

- Ted

Eric Sandeen

author

2012-12-21 17:02 UTC #9 lore raw

In reply to Theodore Ts'o

Quoted 5 lines · Theodore Ts'o

Quoted 3 lines · Jan Kara
I agree. Just I'm still somewhat puzzled by those two reports pointed to
by Eric. In both cases stored tids were 0 and I cannot see how that happens (well how it could happen in a reasonably likely way).

Quoted 7 lines

I'm also really puzzled about how Eric's patch makes a 10% different on the AIM7 benchmark; as you've pointed out, that will just cause an extra wakeup of the jbd/jbd2 thread, which should then quickly check and decide to go back to sleep.
- Ted

Ted, just to double check - is that some wondering aloud, or a NAK of the original patch? :)

-Eric

Theodore Ts'o

maintainer

2012-12-21 17:46 UTC #10 lore raw

Quoted 7 lines · Eric Sandeen

Quoted 4 lines
I'm also really puzzled about how Eric's patch makes a 10% different on the AIM7 benchmark; as you've pointed out, that will just cause an extra wakeup of the jbd/jbd2 thread, which should then quickly check and decide to go back to sleep.
Ted, just to double check - is that some wondering aloud, or a NAK of the original patch? :)

I'm still thinking.... Things that I don't understand worry me, since there's a possibility there's more going on than we think.

Did you have a chance to have your perf people enable the the jbd2_run_stats tracepoint, to see how the stats change with and without the patch?

It would be interesting to see how the stats change --- in particular, whether the number of blocks logged per transaction is changing, and/or the number of blocks per transaction is changing. It would also be interesting to insert a tracepoint in kjournald so we can track the number of times when kjournald is waking, but ends up *not* triggering a commit due to the commit timeout firing or j_commit_sequence != j_commit_request.

I'll probably take the patch on the grounds that it's obvious, but if you could get your perf folks to run the experiment, I'd really appreciate it, just so we can understand what might be going on. Perhaps there's an opportunity for further optimizations, or we'll find that something unexpected that is evidence of a bug. (Or maybe it's just a bug in our understanding, but that's also good to get fixed. :-)

- Ted

Eric Sandeen

author

2013-01-08 20:13 UTC #11 lore raw

Quoted 9 lines · Theodore Ts'o

Quoted 7 lines · Eric Sandeen
Quoted 4 lines
I'm also really puzzled about how Eric's patch makes a 10% different on the AIM7 benchmark; as you've pointed out, that will just cause an extra wakeup of the jbd/jbd2 thread, which should then quickly check and decide to go back to sleep.
Ted, just to double check - is that some wondering aloud, or a NAK of the original patch? :)

Quoted 6 lines

I'm still thinking.... Things that I don't understand worry me, since there's a possibility there's more going on than we think.
Did you have a chance to have your perf people enable the the jbd2_run_stats tracepoint, to see how the stats change with and without the patch?

Getting back to this; grabbing this over a whole AIM7 run would be huge. I wonder if a few snapshots will be illustrative. We can try.

Quoted 7 lines

It would be interesting to see how the stats change --- in particular, whether the number of blocks logged per transaction is changing, and/or the number of blocks per transaction is changing. It would also be interesting to insert a tracepoint in kjournald so we can track the number of times when kjournald is waking, but ends up *not* triggering a commit due to the commit timeout firing or j_commit_sequence != j_commit_request.

Ok, I think I can do that w/ systemtap.

Quoted 7 lines

I'll probably take the patch on the grounds that it's obvious, but if you could get your perf folks to run the experiment, I'd really appreciate it, just so we can understand what might be going on. Perhaps there's an opportunity for further optimizations, or we'll find that something unexpected that is evidence of a bug. (Or maybe it's just a bug in our understanding, but that's also good to get fixed. :-)

I'll see what I can do.

-Eric

Quoted 2 lines

- Ted

Eric Sandeen

author

2013-01-11 16:42 UTC #12 lore raw

In reply to Theodore Ts'o

Quoted 9 lines · Theodore Ts'o

Quoted 7 lines · Eric Sandeen
Quoted 4 lines
I'm also really puzzled about how Eric's patch makes a 10% different on the AIM7 benchmark; as you've pointed out, that will just cause an extra wakeup of the jbd/jbd2 thread, which should then quickly check and decide to go back to sleep.
Ted, just to double check - is that some wondering aloud, or a NAK of the original patch? :)

Quoted 6 lines

I'm still thinking.... Things that I don't understand worry me, since there's a possibility there's more going on than we think.
Did you have a chance to have your perf people enable the the jbd2_run_stats tracepoint, to see how the stats change with and without the patch?

No tracepoint yet, but here's some data from the jbd2 info proc file for a whole AIM7 run, averaged over all devices.

Prior to d9b0193 jbd: fix fsync() tid wraparound bug went in:

3387.93 transaction, each up to 8192 blocks average:
102.661ms waiting for transaction 189ms running transaction
65.375ms transaction was being locked 17.8393ms flushing data (in ordered mode) 164.518ms logging transaction 3694.29us average transaction commit time 2090.05 handles per transaction 12.5893 blocks per transaction 13.5893 logged blocks per transaction

with d9b0193 in place, the benchmark was about 10% slower:

2857.96 transaction, each up to 8192 blocks average:
108.482ms waiting for transaction 266.286ms running transaction 71.625ms transaction was being locked 2.76786ms flushing data (in ordered mode) 252.625ms logging transaction 5932.82us average transaction commit time 2551.21 handles per transaction 43.25 blocks per transaction
44.25 logged blocks per transaction

and with my wake changes:

3775.61 transaction, each up to 8192 blocks average:
92.9286ms waiting for transaction 173.571ms running transaction 60.3036ms transaction was being locked 16.6964ms flushing data (in ordered mode) 149.464ms logging transaction 3849.07us average transaction commit time 1924.84 handles per transaction 13.3036 blocks per transaction 14.3036 logged blocks per transaction

TBH though, this is somewhat opposite of what I'd expect; I thought more wakes might mean smaller transactions - except the wakes were "pointless" - so I'm not quite sure what's going on yet. We can certainly see the difference, though, and that my change gets us back to the prior behavior.

-Eric

Jan Kara

2013-01-11 19:03 UTC #13 lore raw

Quoted 62 lines · Eric Sandeen

Quoted 9 lines · Theodore Ts'o
Quoted 7 lines · Eric Sandeen
Quoted 4 lines
I'm also really puzzled about how Eric's patch makes a 10% different on the AIM7 benchmark; as you've pointed out, that will just cause an extra wakeup of the jbd/jbd2 thread, which should then quickly check and decide to go back to sleep.
Ted, just to double check - is that some wondering aloud, or a NAK of the original patch? :)
Quoted 6 lines
I'm still thinking.... Things that I don't understand worry me, since there's a possibility there's more going on than we think.
Did you have a chance to have your perf people enable the the jbd2_run_stats tracepoint, to see how the stats change with and without the patch?
No tracepoint yet, but here's some data from the jbd2 info proc file for a whole AIM7 run, averaged over all devices.
Prior to d9b0193 jbd: fix fsync() tid wraparound bug went in:
3387.93 transaction, each up to 8192 blocks
average:
102.661ms waiting for transaction
189ms running transaction
65.375ms transaction was being locked
17.8393ms flushing data (in ordered mode)
164.518ms logging transaction
3694.29us average transaction commit time
2090.05 handles per transaction
12.5893 blocks per transaction
13.5893 logged blocks per transaction
with d9b0193 in place, the benchmark was about 10% slower:
2857.96 transaction, each up to 8192 blocks
average:
108.482ms waiting for transaction
266.286ms running transaction
71.625ms transaction was being locked
2.76786ms flushing data (in ordered mode)
252.625ms logging transaction
5932.82us average transaction commit time
2551.21 handles per transaction
43.25 blocks per transaction
44.25 logged blocks per transaction
and with my wake changes:
3775.61 transaction, each up to 8192 blocks
average:
92.9286ms waiting for transaction
173.571ms running transaction
60.3036ms transaction was being locked
16.6964ms flushing data (in ordered mode)
149.464ms logging transaction
3849.07us average transaction commit time
1924.84 handles per transaction
13.3036 blocks per transaction
14.3036 logged blocks per transaction

Quoted 5 lines

TBH though, this is somewhat opposite of what I'd expect; I thought more wakes might mean smaller transactions - except the wakes were "pointless"
- so I'm not quite sure what's going on yet. We can certainly see the difference, though, and that my change gets us back to the prior behavior.

Yes, that's what I'd expect if the difference was really in IO. But
apparently the benchmark is CPU bound on the machine and so the higher amount of work we do under j_state_lock (wake_up() has some small cost after all - it disables interrupts and takes q->lock) results in kjournald taking longer to wake and do its work. It might be interesting to know about how many useless wakeups are we speaking here?

Honza

Signature · 2 lines

Jan Kara <[email protected]>
SUSE Labs, CR

Eric Sandeen

author

2013-01-11 19:07 UTC #14 lore raw

Quoted 1 line · Jan Kara

On Fri 11-01-13 10:42:00, Eric Sandeen wrote:

...

Quoted 11 lines

Quoted 5 lines
TBH though, this is somewhat opposite of what I'd expect; I thought more wakes might mean smaller transactions - except the wakes were "pointless"
- so I'm not quite sure what's going on yet. We can certainly see the difference, though, and that my change gets us back to the prior behavior.
Yes, that's what I'd expect if the difference was really in IO. But
apparently the benchmark is CPU bound on the machine and so the higher amount of work we do under j_state_lock (wake_up() has some small cost after all - it disables interrupts and takes q->lock) results in kjournald taking longer to wake and do its work. It might be interesting to know about how many useless wakeups are we speaking here?

Yeah, I want to get that next.

I think I'll need to instrument the module to get that, the fear is that systemtap might have too much overhead (but I can try both ways).

Thanks,
-Eric

Quoted 2 lines

Honza

Eric Sandeen

author

2012-12-19 15:47 UTC #15 lore raw

In reply to Jan Kara

Quoted 17 lines · Jan Kara

Quoted 16 lines · Eric Sandeen
Quoted 14 lines · Jan Kara
Quoted 13 lines · Jan Kara
Quoted 6 lines
With a u8 tid_t, the "else" clause from commit d9b0193 fires frequently; I really think the underlying problem is that tid_geq() etc does not properly handle wraparounds - if, say, target is 255 and j_commit_request is 0, we don't know if j_commit_request is 255 tids behind, or 1 tid ahead. I have to think about that some more, unless it's obvious to someone else.
Well, there's no way to handle wraps better AFAICT. Tids eventually wrap
and if someone has stored away tid of a transaction he wants committed and keeps it for a long time before using it, it can end up being anywhere before / after current j_commit_request. The hope was that it takes long enough to wrap around 32-bit tids. If this happens often in practice we may have to switch to 64-bit tids (in memory, on disk 32-bit tids are enough because of limited journal size).

Quoted 7 lines

Quoted 4 lines
I was wondering if, since the tid_g*() functions only work if the distance is half the unsigned int space, we can force a commit at some point if j_transaction_sequence has gotten too far ahead? I'm not sure where or if that could be done...
I don't quiete understand. If someone stores tid = transaction->t_tid and
in two weeks calls log_start_commit(tid), I don't see how any forcing of commits could solve that tid may now look ahead of the log...

I'm probably missing something, but I was thinking we could compare j_commit_sequence to j_transaction_sequence and force a commit up to at least j_commit_sequence if it's too "stale" - but I'm only handwaving. :)

-Eric

Quoted 2 lines

Honza

Jan Kara

2012-12-19 17:11 UTC #16 lore raw

Quoted 22 lines · Eric Sandeen

Quoted 21 lines · Jan Kara
Quoted 20 lines · Eric Sandeen
Quoted 7 lines · Jan Kara
Quoted 6 lines · Jan Kara
Quoted 6 lines
With a u8 tid_t, the "else" clause from commit d9b0193 fires frequently; I really think the underlying problem is that tid_geq() etc does not properly handle wraparounds - if, say, target is 255 and j_commit_request is 0, we don't know if j_commit_request is 255 tids behind, or 1 tid ahead. I have to think about that some more, unless it's obvious to someone else.
Quoted 7 lines
Quoted 7 lines
Well, there's no way to handle wraps better AFAICT. Tids eventually wrap
and if someone has stored away tid of a transaction he wants committed and keeps it for a long time before using it, it can end up being anywhere before / after current j_commit_request. The hope was that it takes long enough to wrap around 32-bit tids. If this happens often in practice we may have to switch to 64-bit tids (in memory, on disk 32-bit tids are enough because of limited journal size).
I was wondering if, since the tid_g*() functions only work if the distance is half the unsigned int space, we can force a commit at some point if j_transaction_sequence has gotten too far ahead? I'm not sure where or if that could be done...

Quoted 7 lines

Quoted 3 lines
I don't quiete understand. If someone stores tid = transaction->t_tid and
in two weeks calls log_start_commit(tid), I don't see how any forcing of commits could solve that tid may now look ahead of the log...
I'm probably missing something, but I was thinking we could compare j_commit_sequence to j_transaction_sequence and force a commit up to at least j_commit_sequence if it's too "stale" - but I'm only handwaving. :)

You are probably missing the fact that
j_transaction_sequence - 2 <= j_commit_sequence <= j_transaction_sequence.
I.e., we have always one running transaction and at most one committing
transaction which is the previous one. j_commit_sequence is TID of the transaction which successfully finished commit.

The warnings we are seeing are caused by TIDs stored in EXT3_I(inode)->i_datasync_tid (and i_sync_tid). Those can get rather old before they are used.

Honza

Signature · 2 lines

Jan Kara <[email protected]>
SUSE Labs, CR

Eric Sandeen

author

2012-12-19 02:37 UTC #17 lore raw

In reply to Jan Kara

Quoted 4 lines · Jan Kara

Quoted 3 lines · Eric Sandeen
Commit d9b0193 jbd: fix fsync() tid wraparound bug changed the logic for whether __log_start_commit() should wake up kjournald.

...

Quoted 3 lines

Quoted 2 lines
Anyway, I think this patch helps on the "don't send extra wakeups" side of things. Does anyone see a problem with it?
The patch is fine. I'll queue it up.

Thanks for the review! I'll get jbd2 on the list soon.

-Eric

Quoted 29 lines

Honza
Quoted 28 lines
=============
[PATCH] jbd: don't wake kjournald unnecessarily
Don't send an extra wakeup to kjournald in the case where we already have the proper target in j_commit_request, i.e. that commit has already been requested for commit.
commit d9b0193 "jbd: fix fsync() tid wraparound bug" changed the logic leading to a wakeup, but it caused some extra wakeups which were found to lead to a measurable performance regression.
Signed-off-by Eric Sandeen <[email protected]>
---
fs/jbd/journal.c +2 -1
index a286233..81cc7ea 100644
@@ -446,7 +446,8 @@ int __log_start_commit(journal_t *journal, tid_t target)
 	 * currently running transaction (if it exists).  Otherwise,
 	 * the target tid must be an old one.
 	 */
-	if (journal->j_running_transaction &&
+	if (journal->j_commit_request != target &&
+	    journal->j_running_transaction &&
 	    journal->j_running_transaction->t_tid == target) {
 		/*
 		 * We want a new commit: OK, mark the request and wakeup the

Eric Sandeen

author

2012-12-19 03:01 UTC #18 lore raw

PATCH 1/1 jbd2: don't wake kjournald unnecessarily

In reply to Eric Sandeen

Don't send an extra wakeup to kjournald in the case where we already have the proper target in j_commit_request, i.e. that transaction has already been requested for commit.

commit deeeaf13 "jbd2: fix fsync() tid wraparound bug" changed the logic leading to a wakeup, but it caused some extra wakeups which were found to lead to a measurable performance regression.

Signed-off-by Eric Sandeen <[email protected]>

---

fs/jbd2/journal.c +2 -1

index dbf41f9..89970d5 100644
@@ -518,7 +518,8 @@ int __jbd2_log_start_commit(journal_t *journal, tid_t target)
 	 * currently running transaction (if it exists).  Otherwise,
 	 * the target tid must be an old one.
 	 */
-	if (journal->j_running_transaction &&
+	if (journal->j_commit_request != target &&
+	    journal->j_running_transaction &&
 	    journal->j_running_transaction->t_tid == target) {
 		/*
 		 * We want a new commit: OK, mark the request and wakeup the

Jan Kara

2012-12-19 08:10 UTC #19 lore raw

Re: [PATCH] jbd2: don't wake kjournald unnecessarily

Quoted 9 lines · Eric Sandeen

Don't send an extra wakeup to kjournald in the case where we already have the proper target in j_commit_request, i.e. that transaction has already been requested for commit.
commit deeeaf13 "jbd2: fix fsync() tid wraparound bug" changed the logic leading to a wakeup, but it caused some extra wakeups which were found to lead to a measurable performance regression.
Signed-off-by Eric Sandeen <[email protected]>

Looks good. You can add: Reviewed-by: Jan Kara <[email protected]>

Honza

Quoted 16 lines

---

fs/jbd2/journal.c +2 -1

index dbf41f9..89970d5 100644
@@ -518,7 +518,8 @@ int __jbd2_log_start_commit(journal_t *journal, tid_t target)
 	 * currently running transaction (if it exists).  Otherwise,
 	 * the target tid must be an old one.
 	 */
-	if (journal->j_running_transaction &&
+	if (journal->j_commit_request != target &&
+	    journal->j_running_transaction &&
 	    journal->j_running_transaction->t_tid == target) {
 		/*
 		 * We want a new commit: OK, mark the request and wakeup the

Signature · 2 lines

Jan Kara <[email protected]>
SUSE Labs, CR