I am seeing the following messages in my server's /var/log/messages. They look like stack traces and are not preceded by any narrative (e.g. "such-and-such has gone wrong").
I am almost certain they are related to I/O problems I am experiencing, but it would be instructive to understand what exactly these messages are and what triggers them.
Jan 25 14:56:58 hostname kernel: [15321.586145] master D 000000010016bfbb 0 2753 1 0x00000004 Jan 25 14:56:58 hostname kernel: [15321.586150] ffff88030d053a78 0000000000000086 00000000ffffffff 0000000000015980 Jan 25 14:56:58 hostname kernel: [15321.586156] ffff88030d053fd8 0000000000015980 ffff88030d053fd8 ffff88030dedc4a0 Jan 25 14:56:58 hostname kernel: [15321.586161] 0000000000015980 0000000000015980 ffff88030d053fd8 0000000000015980 Jan 25 14:56:58 hostname kernel: [15321.586166] Call Trace: Jan 25 14:56:58 hostname kernel: [15321.586176] [] do_get_write_access+0x2ed/0x5b0 Jan 25 14:56:58 hostname kernel: [15321.586182] [] ? wake_bit_function+0x0/0x40 Jan 25 14:56:58 hostname kernel: [15321.586189] [] jbd2_journal_get_write_access+0x31/0x50 Jan 25 14:56:58 hostname kernel: [15321.586192] [] __ext4_journal_get_write_access+0x38/0x70 Jan 25 14:56:58 hostname kernel: [15321.586195] [] ext4_reserve_inode_write+0x73/0xa0 Jan 25 14:56:58 hostname kernel: [15321.586197] [] ? jbd2_journal_start+0xb5/0x100 Jan 25 14:56:58 hostname kernel: [15321.586199] [] ext4_mark_inode_dirty+0x4c/0x1d0 Jan 25 14:56:58 hostname kernel: [15321.586200] [] ? ext4_journal_start_sb+0xf8/0x130 Jan 25 14:56:58 hostname kernel: [15321.586202] [] ext4_dirty_inode+0x40/0x60 Jan 25 14:56:58 hostname kernel: [15321.586205] [] __mark_inode_dirty+0x42/0x1d0 Jan 25 14:56:58 hostname kernel: [15321.586207] [] file_update_time+0xfb/0x180 Jan 25 14:56:58 hostname kernel: [15321.586210] [] pipe_write+0x32b/0x670 Jan 25 14:56:58 hostname kernel: [15321.586212] [] do_sync_write+0xda/0x120 Jan 25 14:56:58 hostname kernel: [15321.586215] [] ? apparmor_file_permission+0x18/0x20 Jan 25 14:56:58 hostname kernel: [15321.586218] [] ? security_file_permission+0x16/0x20 Jan 25 14:56:58 hostname kernel: [15321.586220] [] vfs_write+0xb8/0x1a0 Jan 25 14:56:58 hostname kernel: [15321.586221] [] sys_write+0x51/0x80 Jan 25 14:56:58 hostname kernel: [15321.586223] [] ? sys_poll+0x7c/0x110 Jan 25 14:56:58 hostname kernel: [15321.586226] [] system_call_fastpath+0x16/0x1b Jan 25 14:56:58 hostname kernel: [15321.586237] qmgr D 000000010016bfbb 0 2756 2753 0x00000004 Jan 25 14:56:58 hostname kernel: [15321.586239] ffff8802f6cefa98 0000000000000082 ffff880200000000 0000000000015980 Jan 25 14:56:58 hostname kernel: [15321.586241] ffff8802f6ceffd8 0000000000015980 ffff8802f6ceffd8 ffff88030d3c44a0 Jan 25 14:56:58 hostname kernel: [15321.586243] 0000000000015980 0000000000015980 ffff8802f6ceffd8 0000000000015980 Jan 25 14:56:58 hostname kernel: [15321.586245] Call Trace: Jan 25 14:56:58 hostname kernel: [15321.586247] [] do_get_write_access+0x2ed/0x5b0 Jan 25 14:56:58 hostname kernel: [15321.586249] [] ? wake_bit_function+0x0/0x40 Jan 25 14:56:58 hostname kernel: [15321.586251] [] jbd2_journal_get_write_access+0x31/0x50 Jan 25 14:56:58 hostname kernel: [15321.586253] [] __ext4_journal_get_write_access+0x38/0x70 Jan 25 14:56:58 hostname kernel: [15321.586255] [] ext4_reserve_inode_write+0x73/0xa0 Jan 25 14:56:58 hostname kernel: [15321.586257] [] ? jbd2_journal_start+0xb5/0x100 Jan 25 14:56:58 hostname kernel: [15321.586258] [] ext4_mark_inode_dirty+0x4c/0x1d0 Jan 25 14:56:58 hostname kernel: [15321.586260] [] ? ext4_journal_start_sb+0xf8/0x130 Jan 25 14:56:58 hostname kernel: [15321.586263] [] ? ep_poll_callback+0xbb/0xf0 Jan 25 14:56:58 hostname kernel: [15321.586265] [] ext4_dirty_inode+0x40/0x60 Jan 25 14:56:58 hostname kernel: [15321.586266] [] __mark_inode_dirty+0x42/0x1d0 Jan 25 14:56:58 hostname kernel: [15321.586268] [] touch_atime+0x135/0x180 Jan 25 14:56:58 hostname kernel: [15321.586270] [] pipe_read+0x2b4/0x4a0 Jan 25 14:56:58 hostname kernel: [15321.586272] [] do_sync_read+0xda/0x120 Jan 25 14:56:58 hostname kernel: [15321.586275] [] ? default_spin_lock_flags+0x9/0x10 Jan 25 14:56:58 hostname kernel: [15321.586276] [] ? ep_poll+0xab/0x2a0 Jan 25 14:56:58 hostname kernel: [15321.586278] [] ? apparmor_file_permission+0x18/0x20 Jan 25 14:56:58 hostname kernel: [15321.586280] [] ? security_file_permission+0x16/0x20 Jan 25 14:56:58 hostname kernel: [15321.586282] [] vfs_read+0xb5/0x1a0 Jan 25 14:56:58 hostname kernel: [15321.586283] [] sys_read+0x51/0x80 Jan 25 14:56:58 hostname kernel: [15321.586285] [] ? sys_epoll_wait+0x96/0xe0 Jan 25 14:56:58 hostname kernel: [15321.586287] [] system_call_fastpath+0x16/0x1b
The kernel is Linux hostname 2.6.35-24-generic #42-Ubuntu SMP Thu Dec 2 02:41:37 UTC 2010 x86_64 GNU/Linux
It specifically looks as though ext4 is experiencing difficulty in writing data to the journal. My experience with ext3 was that the journal is used for writing the metadata you are about to commit to a safe place where it can at least be undone in the event of a system crash. Since writing to the journal is a non-critical, albeit important, function it probably just does an oops and rolls on. Since the system didn't crash at that moment, you only experience a delay during the time the ext4 kernel module was having issues with the journal.
So why is the filesystem having trouble with the journal? Look at the following questions to see if they spark any more ideas: