Thanks for helping.
What I did:
-> Rebooted on the mandriva, everything is fine, copying a file of 50Megs from /dev/hda3 to itself takes less than a second.
=> My disk seems fine, the partition is not the problem
-> Rebooted on debian, copying the same file takes more than 10seconds
with my fan going crazy... 80% in Software Interrupt.
=> Specific to my kernel or my kernel configuration or installed software..
-> ran init 1 , did the same test (on debian), same problem.
=> No network deamons, no apps anymore..
=> I see kjournald and pdflush going crazy in top
-> activated JBD_DEBUG in the kernel and put the logging level to 5
I get the log below, I have to analyse.. maybe I have to activate logging in the interrupt handler.
Any expert help would be highly apprciated.
tail /var/log/kernel.log while copying a 50Meg file from /dev/hda3 (/) on itself :
41 (jbd/transaction.c, 941): journal_dirty_data: jh: cd36eee8, tid:1751148
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
41 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 1 credits (total 4, free 1969)
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 1373): journal_stop: transaction too old, requesting commit for handle c27612a4
41 (jbd/journal.c, 453): __log_start_commit: JBD: requesting commit 1751148/1751147
41 (jbd/journal.c, 205): kjournald: kjournald wakes
41 (jbd/journal.c, 159): kjournald: commit_sequence=1751147, commit_request=1751148
41 (jbd/journal.c, 162): kjournald: OK, requests differ
41 (jbd/commit.c, 202): journal_commit_transaction: superblock not updated
41 (jbd/commit.c, 212): journal_commit_transaction: JBD: starting commit of transaction 1751148
41 (jbd/commit.c, 282): journal_commit_transaction: JBD: commit phase 1
41 (jbd/commit.c, 296): journal_commit_transaction: JBD: commit phase 2
41 (jbd/commit.c, 359): journal_commit_transaction: submit 512 writes
41 (jbd/journal.c, 550): log_wait_commit: JBD: want 1751148, j_commit_sequence=1751bd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
41 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
41 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
41 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
41 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 11, free 1746)
41 (jbd/transaction.c, 941): journal_dirty_data: jh: cd36ee80, tid:1751197
41 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
41 (jbd/transaction.c, 540): do_get_write_access: buffer_head ddfebe4c, force_copy 0
41 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head ddfebe4c, cancelling revoke
41 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head ddfebe4c
41 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
41 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 12, free 1746)
41 (jbd/transaction.c, 941): journal_dirty_data: jh: defc1320, tid:1751197
41 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
41 (jbd/transaction.c, 540): do_get_write_access: buffer_head dea4bcac, force_copy 0
41 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head dea4bcac, cancelling revoke
41 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head dea4bcac
41 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
41 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1746)
41 (jbd/transaction.c, 941): journal_dirty_data: jh: cd36eee8, tid:1751197
41 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
41 (jbd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
41 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
41 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
41 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
41 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1746)
41 (jbd/transaction.c, 941): journal_dirty_data: jh: cd36eee8, tid:1751197
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
41 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 1 credits (total 4, free 1746)
41 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
41 (jbd/transaction.c, 1373): journal_stop: transaction too old, requesting commit for handle c27612a4
41 (jbd/journal.c, 453): __log_start_commit: JBD: requesting commit 1751197/1751196
41 (jbd/journal.c, 205): kjournald: kjournald wakes
41 (jbd/journal.c, 159): kjournald: commit_sequence=1751196, commit_request=1751197
41 (jbd/journal.c, 162): kjournald: OK, requests differ
41 (jbd/commit.c, 202): journal_commit_transaction: superblock not updated
41 (jbd/commit.c, 212): journal_commit_transaction: JBD: starting commit of transaction 1751197
41 (jbd/commit.c, 282): journal_commit_transaction: JBD: commit phase 1
42 (jbd/commit.c, 296): journal_commit_transaction: JBD: commit phase 2
42 (jbd/commit.c, 359): journal_commit_transaction: submit 512 writes
42 (jbd/journal.c, 550): log_wait_commit: JBD: want 1751197, j_commit_sequence=1751bd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
42 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
42 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
42 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
42 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
42 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 11, free 1519)
42 (jbd/transaction.c, 941): journal_dirty_data: jh: c0939ba8, tid:1751246
42 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
42 (jbd/transaction.c, 540): do_get_write_access: buffer_head ddfebe4c, force_copy 0
42 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head ddfebe4c, cancelling revoke
42 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head ddfebe4c
42 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
42 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
42 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 12, free 1519)
42 (jbd/transaction.c, 941): journal_dirty_data: jh: df4039a0, tid:1751246
42 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
42 (jbd/transaction.c, 540): do_get_write_access: buffer_head dea4bcac, force_copy 0
42 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head dea4bcac, cancelling revoke
42 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head dea4bcac
42 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
42 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
42 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1519)
42 (jbd/transaction.c, 941): journal_dirty_data: jh: df4039d4, tid:1751246
42 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
42 (jbd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
42 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
42 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
42 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
42 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
42 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1519)
42 (jbd/transaction.c, 941): journal_dirty_data: jh: df4039d4, tid:1751246
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
42 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
42 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 1 credits (total 4, free 1519)
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
42 (jbd/transaction.c, 1373): journal_stop: transaction too old, requesting commit for handle c27612a4
42 (jbd/journal.c, 453): __log_start_commit: JBD: requesting commit 1751246/1751245
42 (jbd/journal.c, 205): kjournald: kjournald wakes
42 (jbd/journal.c, 159): kjournald: commit_sequence=1751245, commit_request=1751246
42 (jbd/journal.c, 162): kjournald: OK, requests differ
42 (jbd/commit.c, 202): journal_commit_transaction: superblock not updated
42 (jbd/commit.c, 212): journal_commit_transaction: JBD: starting commit of transaction 1751246
42 (jbd/commit.c, 282): journal_commit_transaction: JBD: commit phase 1
42 (jbd/commit.c, 296): journal_commit_transaction: JBD: commit phase 2
42 (jbd/commit.c, 359): journal_commit_transaction: submit 512 writes
42 (jbd/journal.c, 550): log_wait_commit: JBD: want 1751246, j_commit_sequence=1751bd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
42 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
42 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
42 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
42 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
42 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 11, free 1291)
42 (jbd/transaction.c, 941): journal_dirty_data: jh: dc4d3eb4, tid:1751295
42 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
42 (jbd/transaction.c, 540): do_get_write_access: buffer_head ddfebe4c, force_copy 0
42 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head ddfebe4c, cancelling revoke
42 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head ddfebe4c
42 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
42 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
43 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
43 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 12, free 1291)
43 (jbd/transaction.c, 941): journal_dirty_data: jh: db81fee8, tid:1751295
43 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
43 (jbd/transaction.c, 540): do_get_write_access: buffer_head dea4bcac, force_copy 0
43 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head dea4bcac, cancelling revoke
43 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head dea4bcac
43 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
43 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
43 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
43 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1291)
43 (jbd/transaction.c, 941): journal_dirty_data: jh: df403a70, tid:1751295
43 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
43 (jbd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
43 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
43 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
43 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
43 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
43 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
43 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1291)
43 (jbd/transaction.c, 941): journal_dirty_data: jh: df403a70, tid:1751295
43 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
43 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
43 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 1 credits (total 4, free 1291)
43 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
43 (jbd/transaction.c, 1373): journal_stop: transaction too old, requesting commit for handle c27612a4
43 (jbd/journal.c, 453): __log_start_commit: JBD: requesting commit 1751295/1751294
43 (jbd/journal.c, 205): kjournald: kjournald wakes
43 (jbd/journal.c, 159): kjournald: commit_sequence=1751294, commit_request=1751295
43 (jbd/journal.c, 162): kjournald: OK, requests differ
43 (jbd/commit.c, 202): journal_commit_transaction: superblock not updated
43 (jbd/commit.c, 212): journal_commit_transaction: JBD: starting commit of transaction 1751295
43 (jbd/commit.c, 282): journal_commit_transaction: JBD: commit phase 1
43 (jbd/commit.c, 296): journal_commit_transaction: JBD: commit phase 2
43 (jbd/commit.c, 359): journal_commit_transaction: submit 512 writes
43 (jbd/journal.c, 550): log_wait_commit: JBD: want 1751295, j_commit_sequence=1751bd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
43 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
43 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
43 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
43 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
43 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
43 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 11, free 1068)
43 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f62c, tid:1751344
43 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
43 (jbd/transaction.c, 540): do_get_write_access: buffer_head ddfebe4c, force_copy 0
43 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head ddfebe4c, cancelling revoke
43 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head ddfebe4c
43 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
43 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
43 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
43 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 12, free 1068)
43 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f458, tid:1751344
43 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
44 (jbd/transaction.c, 540): do_get_write_access: buffer_head dea4bcac, force_copy 0
44 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head dea4bcac, cancelling revoke
44 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head dea4bcac
44 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
44 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1068)
44 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f424, tid:1751344
44 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
44 (jbd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
44 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
44 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
44 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
44 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 1068)
44 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f424, tid:1751344
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
44 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 1 credits (total 4, free 1068)
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 1373): journal_stop: transaction too old, requesting commit for handle c27612a4
44 (jbd/journal.c, 453): __log_start_commit: JBD: requesting commit 1751344/1751343
44 (jbd/journal.c, 205): kjournald: kjournald wakes
44 (jbd/journal.c, 159): kjournald: commit_sequence=1751343, commit_request=1751344
44 (jbd/journal.c, 162): kjournald: OK, requests differ
44 (jbd/commit.c, 202): journal_commit_transaction: superblock not updated
44 (jbd/commit.c, 212): journal_commit_transaction: JBD: starting commit of transaction 1751344
44 (jbd/commit.c, 282): journal_commit_transaction: JBD: commit phase 1
44 (jbd/commit.c, 296): journal_commit_transaction: JBD: commit phase 2
44 (jbd/commit.c, 359): journal_commit_transaction: submit 512 writes
44 (jbd/journal.c, 550): log_wait_commit: JBD: want 1751344, j_commit_sequence=1751s/jbd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
44 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
44 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
44 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
44 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 11, free 3240)
44 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f388, tid:1751393
44 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
44 (jbd/transaction.c, 540): do_get_write_access: buffer_head ddfebe4c, force_copy 0
44 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head ddfebe4c, cancelling revoke
44 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head ddfebe4c
44 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
44 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 12, free 3240)
44 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f3bc, tid:1751393
44 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
44 (jbd/transaction.c, 540): do_get_write_access: buffer_head dea4bcac, force_copy 0
44 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head dea4bcac, cancelling revoke
44 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head dea4bcac
44 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
44 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 3240)
44 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f320, tid:1751393
44 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=c27612a4
44 (jbd/transaction.c, 540): do_get_write_access: buffer_head d3a013f0, force_copy 0
44 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head d3a013f0, cancelling revoke
44 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d3a013f0
44 (jbd/transaction.c, 1322): journal_stop: h_ref 2 -> 1
44 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
44 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
45 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 10 credits (total 13, free 3240)
45 (jbd/transaction.c, 941): journal_dirty_data: jh: db81f320, tid:1751393
45 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
45 (jbd/transaction.c, 107): start_this_handle: New handle c27612a4 going live.
45 (jbd/transaction.c, 226): start_this_handle: Handle c27612a4 given 1 credits (total 4, free 3240)
45 (jbd/transaction.c, 1326): journal_stop: Handle c27612a4 going down
45 (jbd/transaction.c, 1373): journal_stop: transaction too old, requesting commit for handle c27612a4
45 (jbd/journal.c, 453): __log_start_commit: JBD: requesting commit 1751393/1751392
45 (jbd/journal.c, 205): kjournald: kjournald wakes
45 (jbd/journal.c, 159): kjournald: commit_sequence=1751392, commit_request=1751393
45 (jbd/journal.c, 162): kjournald: OK, requests differ
45 (jbd/commit.c, 202): journal_commit_transaction: superblock not updated
45 (jbd/commit.c, 212): journal_commit_transaction: JBD: starting commit of transaction 1751393
45 (jbd/commit.c, 282): journal_commit_transaction: JBD: commit phase 1
45 (jbd/commit.c, 296): journal_commit_transaction: JBD: commit phase 2
45 (jbd/commit.c, 359): journal_commit_transaction: submit 512 writes
45 (jbd/journal.c, 550): log_wait_commit: JBD: want 1751393, j_commit_sequence=1ng revoke
45 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head d5f7248c
45 (jbd/transaction.c, 1326): journal_stop: Handle c27612b8 going down
45 (jbd/transaction.c, 107): start_this_handle: New handle c27612b8 going live.
45 (jbd/transaction.c, 226): start_this_handle: Handle c27612b8 given 2 credits (total 18, free 5005)
45 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=00000000
45 (jbd/transaction.c, 540): do_get_write_access: buffer_head de76d730, force_copy 0
45 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head de76d730, cancelling revoke
45 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head de76d730
45 (jbd/transaction.c, 1326): journal_stop: Handle c27612b8 going down
45 (jbd/transaction.c, 107): start_this_handle: New handle c27612b8 going live.
45 (jbd/transaction.c, 226): start_this_handle: Handle c27612b8 given 2 credits (total 18, free 5005)
45 (ext3/inode.c, 2975): ext3_dirty_inode: marking dirty.outer handle=00000000
45 (jbd/transaction.c, 540): do_get_write_access: buffer_head ddfeba70, force_copy 0
45 (jbd/revoke.c, 428): journal_cancel_revoke: journal_head ddfeba70, cancelling revoke
45 (jbd/transaction.c, 1100): journal_dirty_metadata: journal_head ddfeba70
45 (jbd/transaction.c, 1326): journal_stop: Handle c27612b8 going down