Message ID | 20110624134659.GB26380@quack.suse.cz |
---|---|
State | New, archived |
Headers | show |
On Jun 24, 2011, at 09:46, Jan Kara wrote: > On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: >> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this >> one: >> >> J_ASSERT(commit_transaction->t_nr_buffers <= >> commit_transaction->t_outstanding_credits); > > Hmm, OK, so we've used more metadata buffers than we told JBD2 to > reserve. I suppose you are not using data=journal mode and the filesystem > was created as ext4 (i.e. not converted from ext3), right? Are you using > quotas? The filesystem *is* using data=journal mode. If I switch to data=ordered or data=writeback, the problem goes away. The filesystems were created as ext4 using the e2fstools in Debian squeeze: 1.41.12, and the kernel package is 2.6.32-5-xen-amd64 (2.6.32-34squeeze1). The exact commands I used to create the Postfix filesystems were: lvcreate -L 5G -n postfix dbnew lvcreate -L 32M -n smtp dbnew mke2fs -t ext4 -L db:postfix /dev/dbnew/postfix mke2fs -t ext4 -L db:smtp /dev/dbnew/smtp tune2fs -i 0 -c 1 -e remount-ro -o acl,user_xattr,journal_data /dev/dbnew/postfix tune2fs -i 0 -c 1 -e remount-ro -o acl,user_xattr,journal_data /dev/dbnew/smtp Then my fstab has: /dev/mapper/dbnew-postfix /var/spool/postfix ext4 noauto,noatime,nosuid,nodev 0 2 /dev/mapper/dbnew-smtp /var/lib/postfix ext4 noauto,noatime,nosuid,nodev 0 2 I don't even think I have the quota tools installed on this system; there are certainly none configured. >> If somebody can tell me what information would help to debug this I'd be >> more than happy to throw a whole bunch of debug printks under that error >> condition and try to trigger the crash with that. >> >> Alternatively I could remove that J_ASSERT() and instead add some debug >> further down around the "commit_transaction->t_outstanding_credits--;" >> to try to see exactly what IO it's handling when it runs out of credits. > > The trouble is that the problem is likely in some journal list shuffling > code because if just some operation wrongly estimated the number of needed > buffers, we'd fail the assertion in jbd2_journal_dirty_metadata(): > J_ASSERT_JH(jh, handle->h_buffer_credits > 0); Hmm, ok... I'm also going to turn that failing J_ASSERT() into a WARN_ON() just to see how much further it gets. I have an easy script to recreate this data volume even if it gets totally hosed anyways, so... > The patch below might catch the problem closer to the place where it > happens... > > Also possibly you can try current kernel whether the bug happens with it or > not. I'm definitely going to try this patch, but I'll also see what I can do about trying a more recent kernel. Thanks! Cheers, Kyle Moffett -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Fri 24-06-11 11:03:52, Moffett, Kyle D wrote: > On Jun 24, 2011, at 09:46, Jan Kara wrote: > > On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: > >> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this > >> one: > >> > >> J_ASSERT(commit_transaction->t_nr_buffers <= > >> commit_transaction->t_outstanding_credits); > > > > Hmm, OK, so we've used more metadata buffers than we told JBD2 to > > reserve. I suppose you are not using data=journal mode and the filesystem > > was created as ext4 (i.e. not converted from ext3), right? Are you using > > quotas? > > The filesystem *is* using data=journal mode. If I switch to data=ordered > or data=writeback, the problem goes away. Ah, OK. Then bug https://bugzilla.kernel.org/show_bug.cgi?id=34642 is probably ext3 incarnation of the same problem and it seems it's still present even in the current kernel - that ext3 assertion triggered even with 2.6.39 kernel. Frankly data=journal mode is far less tested than the other two modes especially with ext4, so I'm not sure how good idea is to use it in production. > The filesystems were created as ext4 using the e2fstools in Debian squeeze: > 1.41.12, and the kernel package is 2.6.32-5-xen-amd64 (2.6.32-34squeeze1). > > The exact commands I used to create the Postfix filesystems were: > lvcreate -L 5G -n postfix dbnew > lvcreate -L 32M -n smtp dbnew > mke2fs -t ext4 -L db:postfix /dev/dbnew/postfix > mke2fs -t ext4 -L db:smtp /dev/dbnew/smtp > tune2fs -i 0 -c 1 -e remount-ro -o acl,user_xattr,journal_data /dev/dbnew/postfix > tune2fs -i 0 -c 1 -e remount-ro -o acl,user_xattr,journal_data /dev/dbnew/smtp > > Then my fstab has: > /dev/mapper/dbnew-postfix /var/spool/postfix ext4 noauto,noatime,nosuid,nodev 0 2 > /dev/mapper/dbnew-smtp /var/lib/postfix ext4 noauto,noatime,nosuid,nodev 0 2 > > I don't even think I have the quota tools installed on this system; there > are certainly none configured. OK, thanks. > >> If somebody can tell me what information would help to debug this I'd be > >> more than happy to throw a whole bunch of debug printks under that error > >> condition and try to trigger the crash with that. > >> > >> Alternatively I could remove that J_ASSERT() and instead add some debug > >> further down around the "commit_transaction->t_outstanding_credits--;" > >> to try to see exactly what IO it's handling when it runs out of credits. > > > > The trouble is that the problem is likely in some journal list shuffling > > code because if just some operation wrongly estimated the number of needed > > buffers, we'd fail the assertion in jbd2_journal_dirty_metadata(): > > J_ASSERT_JH(jh, handle->h_buffer_credits > 0); > > Hmm, ok... I'm also going to turn that failing J_ASSERT() into a WARN_ON() > just to see how much further it gets. I have an easy script to recreate this > data volume even if it gets totally hosed anyways, so... OK, we'll see what happens. > > The patch below might catch the problem closer to the place where it > > happens... > > > > Also possibly you can try current kernel whether the bug happens with it or > > not. > > I'm definitely going to try this patch, but I'll also see what I can do about > trying a more recent kernel. Honza
On Fri, 24 Jun 2011, Jan Kara wrote: > On Fri 24-06-11 11:03:52, Moffett, Kyle D wrote: > > On Jun 24, 2011, at 09:46, Jan Kara wrote: > > > On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: > > >> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this > > >> one: > > >> > > >> J_ASSERT(commit_transaction->t_nr_buffers <= > > >> commit_transaction->t_outstanding_credits); > > > > > > Hmm, OK, so we've used more metadata buffers than we told JBD2 to > > > reserve. I suppose you are not using data=journal mode and the filesystem > > > was created as ext4 (i.e. not converted from ext3), right? Are you using > > > quotas? > > > > The filesystem *is* using data=journal mode. If I switch to data=ordered > > or data=writeback, the problem goes away. > Ah, OK. Then bug https://bugzilla.kernel.org/show_bug.cgi?id=34642 is > probably ext3 incarnation of the same problem and it seems it's still > present even in the current kernel - that ext3 assertion triggered even > with 2.6.39 kernel. Frankly data=journal mode is far less tested than the > other two modes especially with ext4, so I'm not sure how good idea is to > use it in production. Hi Jan, if it is so (and it probably is, since I am not testing this mode as well:), it would be interesting to find out whether there are many users of this and if there are not, which is probably the case, deprecate it now, so we can remove it later. If we are openly suggesting not to use this, then there is probably no point in having this option in the first place. I vaguely remember that Ted said something about removing data=journal mode, but I do not remember details. Ted ? Thanks! -Lukas -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon, Jun 27, 2011 at 2:16 PM, Lukas Czerner <lczerner@redhat.com> wrote: > On Fri, 24 Jun 2011, Jan Kara wrote: > >> On Fri 24-06-11 11:03:52, Moffett, Kyle D wrote: >> > On Jun 24, 2011, at 09:46, Jan Kara wrote: >> > > On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: >> > >> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this >> > >> one: >> > >> >> > >> J_ASSERT(commit_transaction->t_nr_buffers <= >> > >> commit_transaction->t_outstanding_credits); >> > > >> > > Hmm, OK, so we've used more metadata buffers than we told JBD2 to >> > > reserve. I suppose you are not using data=journal mode and the filesystem >> > > was created as ext4 (i.e. not converted from ext3), right? Are you using >> > > quotas? >> > >> > The filesystem *is* using data=journal mode. If I switch to data=ordered >> > or data=writeback, the problem goes away. >> Ah, OK. Then bug https://bugzilla.kernel.org/show_bug.cgi?id=34642 is >> probably ext3 incarnation of the same problem and it seems it's still >> present even in the current kernel - that ext3 assertion triggered even >> with 2.6.39 kernel. Frankly data=journal mode is far less tested than the >> other two modes especially with ext4, so I'm not sure how good idea is to >> use it in production. > > Hi Jan, > > if it is so (and it probably is, since I am not testing this mode as > well:), it would be interesting to find out whether there are many users > of this and if there are not, which is probably the case, deprecate it now, > so we can remove it later. If we are openly suggesting not to use this, > then there is probably no point in having this option in the first > place. > > I vaguely remember that Ted said something about removing data=journal > mode, but I do not remember details. Ted ? > I think Ted was plotting about removing data=ordered... Amir. -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon 27-06-11 13:16:50, Lukas Czerner wrote: > On Fri, 24 Jun 2011, Jan Kara wrote: > > > On Fri 24-06-11 11:03:52, Moffett, Kyle D wrote: > > > On Jun 24, 2011, at 09:46, Jan Kara wrote: > > > > On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: > > > >> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this > > > >> one: > > > >> > > > >> J_ASSERT(commit_transaction->t_nr_buffers <= > > > >> commit_transaction->t_outstanding_credits); > > > > > > > > Hmm, OK, so we've used more metadata buffers than we told JBD2 to > > > > reserve. I suppose you are not using data=journal mode and the filesystem > > > > was created as ext4 (i.e. not converted from ext3), right? Are you using > > > > quotas? > > > > > > The filesystem *is* using data=journal mode. If I switch to data=ordered > > > or data=writeback, the problem goes away. > > Ah, OK. Then bug https://bugzilla.kernel.org/show_bug.cgi?id=34642 is > > probably ext3 incarnation of the same problem and it seems it's still > > present even in the current kernel - that ext3 assertion triggered even > > with 2.6.39 kernel. Frankly data=journal mode is far less tested than the > > other two modes especially with ext4, so I'm not sure how good idea is to > > use it in production. Hi Lukas, > if it is so (and it probably is, since I am not testing this mode as > well:), it would be interesting to find out whether there are many users > of this and if there are not, which is probably the case, deprecate it now, > so we can remove it later. If we are openly suggesting not to use this, > then there is probably no point in having this option in the first > place. For about one year I'm trying to look for people using data=journal and I've found some. So although data=journal users are minority, there are some. That being said I agree with you we should do something about it - either state that we want to fully support data=journal - and then we should really do better with testing it or deprecate it and remove it (which would save us some complications in the code). I would be slightly in favor of removing it (code simplicity, less options to configure for admin, less options to test for us, some users I've come across actually were not quite sure why they are using it - they just thought it looks safer). Honza
On Mon, 27 Jun 2011, Jan Kara wrote: > On Mon 27-06-11 13:16:50, Lukas Czerner wrote: > > On Fri, 24 Jun 2011, Jan Kara wrote: > > > > > On Fri 24-06-11 11:03:52, Moffett, Kyle D wrote: > > > > On Jun 24, 2011, at 09:46, Jan Kara wrote: > > > > > On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: > > > > >> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this > > > > >> one: > > > > >> > > > > >> J_ASSERT(commit_transaction->t_nr_buffers <= > > > > >> commit_transaction->t_outstanding_credits); > > > > > > > > > > Hmm, OK, so we've used more metadata buffers than we told JBD2 to > > > > > reserve. I suppose you are not using data=journal mode and the filesystem > > > > > was created as ext4 (i.e. not converted from ext3), right? Are you using > > > > > quotas? > > > > > > > > The filesystem *is* using data=journal mode. If I switch to data=ordered > > > > or data=writeback, the problem goes away. > > > Ah, OK. Then bug https://bugzilla.kernel.org/show_bug.cgi?id=34642 is > > > probably ext3 incarnation of the same problem and it seems it's still > > > present even in the current kernel - that ext3 assertion triggered even > > > with 2.6.39 kernel. Frankly data=journal mode is far less tested than the > > > other two modes especially with ext4, so I'm not sure how good idea is to > > > use it in production. > > Hi Lukas, > > > if it is so (and it probably is, since I am not testing this mode as > > well:), it would be interesting to find out whether there are many users > > of this and if there are not, which is probably the case, deprecate it now, > > so we can remove it later. If we are openly suggesting not to use this, > > then there is probably no point in having this option in the first > > place. > For about one year I'm trying to look for people using data=journal and > I've found some. So although data=journal users are minority, there are > some. That being said I agree with you we should do something about it > - either state that we want to fully support data=journal - and then we > should really do better with testing it or deprecate it and remove it > (which would save us some complications in the code). > > I would be slightly in favor of removing it (code simplicity, less options > to configure for admin, less options to test for us, some users I've come > across actually were not quite sure why they are using it - they just > thought it looks safer). > > Honza > I completely agree with you. Also I find it really dangerous that the option which looks much safer is in fact less safe, because just a minority of people (including developers) are testing it. Thanks! -Lukas -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon, Jun 27, 2011 at 05:30:11PM +0200, Lukas Czerner wrote: > > I've found some. So although data=journal users are minority, there are > > some. That being said I agree with you we should do something about it > > - either state that we want to fully support data=journal - and then we > > should really do better with testing it or deprecate it and remove it > > (which would save us some complications in the code). > > > > I would be slightly in favor of removing it (code simplicity, less options > > to configure for admin, less options to test for us, some users I've come > > across actually were not quite sure why they are using it - they just > > thought it looks safer). Hmm... FYI, I hope to be able to bring on line automated testing for ext4 later this summer (there's a testing person at Google is has signed up to work on setting this up as his 20% project). The test matrix that I have him included data=journal, so we will be getting better testing in the near future. At least historically, data=journalling was the *simpler* case, and was the first thing supported by ext4. (data=ordered required revoke handling which didn't land for six months or so). So I'm not really that convinced that removing really buys us that much code simplification. That being siad, it is true that data=journalled isn't necessarily faster. For heavy disk-bound workloads, it can be slower. So I can imagine adding some documentation that warns people not to use data=journal unless they really know what they are doing, but at least personally, I'm a bit reluctant to dispense with a bug report like this by saying, "oh, that feature should be deprecated". Regards, - Ted -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon 27-06-11 12:01:40, Ted Tso wrote: > On Mon, Jun 27, 2011 at 05:30:11PM +0200, Lukas Czerner wrote: > > > I've found some. So although data=journal users are minority, there are > > > some. That being said I agree with you we should do something about it > > > - either state that we want to fully support data=journal - and then we > > > should really do better with testing it or deprecate it and remove it > > > (which would save us some complications in the code). > > > > > > I would be slightly in favor of removing it (code simplicity, less options > > > to configure for admin, less options to test for us, some users I've come > > > across actually were not quite sure why they are using it - they just > > > thought it looks safer). > > Hmm... FYI, I hope to be able to bring on line automated testing for > ext4 later this summer (there's a testing person at Google is has > signed up to work on setting this up as his 20% project). The test > matrix that I have him included data=journal, so we will be getting > better testing in the near future. Good! > At least historically, data=journalling was the *simpler* case, and > was the first thing supported by ext4. (data=ordered required revoke > handling which didn't land for six months or so). So I'm not really > that convinced that removing really buys us that much code > simplification. It does buy us some reduction in number of variants (e.g. write_begin, write_end, writepage), we also wouldn't have to care about journalled data during invalidatepage() or releasepage() calls. > That being siad, it is true that data=journalled isn't necessarily > faster. For heavy disk-bound workloads, it can be slower. So I can > imagine adding some documentation that warns people not to use > data=journal unless they really know what they are doing, but at least > personally, I'm a bit reluctant to dispense with a bug report like > this by saying, "oh, that feature should be deprecated". No, I didn't want to dispense the bug report - we should definitely fix the bug. I just remarked that data=journal is currently not well tested and thus using it in production has its problems. Honza
On Jun 27, 2011, at 12:01, Ted Ts'o wrote: > On Mon, Jun 27, 2011 at 05:30:11PM +0200, Lukas Czerner wrote: >>> I've found some. So although data=journal users are minority, there are >>> some. That being said I agree with you we should do something about it >>> - either state that we want to fully support data=journal - and then we >>> should really do better with testing it or deprecate it and remove it >>> (which would save us some complications in the code). >>> >>> I would be slightly in favor of removing it (code simplicity, less options >>> to configure for admin, less options to test for us, some users I've come >>> across actually were not quite sure why they are using it - they just >>> thought it looks safer). > > Hmm... FYI, I hope to be able to bring on line automated testing for > ext4 later this summer (there's a testing person at Google is has > signed up to work on setting this up as his 20% project). The test > matrix that I have him included data=journal, so we will be getting > better testing in the near future. > > At least historically, data=journalling was the *simpler* case, and > was the first thing supported by ext4. (data=ordered required revoke > handling which didn't land for six months or so). So I'm not really > that convinced that removing really buys us that much code > simplification. > > That being siad, it is true that data=journalled isn't necessarily > faster. For heavy disk-bound workloads, it can be slower. So I can > imagine adding some documentation that warns people not to use > data=journal unless they really know what they are doing, but at least > personally, I'm a bit reluctant to dispense with a bug report like > this by saying, "oh, that feature should be deprecated". I suppose I should chime in here, since I'm the one who (potentially incorrectly) thinks I should be using data=journalled mode. My basic impression is that the use of "data=journalled" can help reduce the risk (slightly) of serious corruption to some kinds of databases when the application does not provide appropriate syncs or journalling on its own (IE: such as text-based Wiki database files). Please correct me if this is horribly horribly wrong: no journal: Nothing is journalled + Very fast. + Works well for filesystems that are "mkfs"ed on every boot - Have to fsck after every reboot data=writeback: Metadata is journalled, data (to allocated extents) may be written before or after the metadata is updated with a new file size. + Fast (not as fast as unjournalled) + No need to "fsck" after a hard power-down - A crash or power failure in the middle of a write could leave old data on disk at the end of a file. If security labeling such as SELinux is enabled, this could "contaminate" a file with data from a deleted file that was at a higher sensitivity. Log files (including binary database replication logs) may be effectively corrupted as a result. data=ordered: Data appended to a file will be written before the metadata extending the length of the file is written, and in certain cases the data will be written before file renames (partial ordering), but the data itself is unjournalled, and may be only partially complete for updates. + Does not write data to the media twice + A crash or power failure will not leave old uninitialized data in files. - Data writes to files may only partially complete in the event of a crash. No problems for logfiles, or self-journalled application databases, but others may experience partial writes in the event of a crash and need recovery. data=journalled: Data and metadata are both journalled, meaning that a given data write will either complete or it will never occur, although the precise ordering is not guaranteed. This also implies all of the data<=>metadata guarantees of data=ordered. + Direct IO data writes are effectively "atomic", resulting in less likelihood of data loss for application databases which do not do their own journalling. This means that a power failure or system crash will not result in a partially-complete write. - Cached writes are not atomic + For small cached file writes (of only a few filesystem pages) there is a good chance that kernel writeback will queue the entire write as a single I/O and it will be "protected" as a result. This helps reduce the chance of serious damage to some text-based database files (such as those for some Wikis), but is obviously not a guarantee. - This writes all data to the block device twice (once to the FS journal and once to the data blocks). This may be especially bad for write-limited Flash-backed devices. Cheers, Kyle Moffett -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon 27-06-11 23:21:17, Moffett, Kyle D wrote: > On Jun 27, 2011, at 12:01, Ted Ts'o wrote: > > On Mon, Jun 27, 2011 at 05:30:11PM +0200, Lukas Czerner wrote: > >>> I've found some. So although data=journal users are minority, there are > >>> some. That being said I agree with you we should do something about it > >>> - either state that we want to fully support data=journal - and then we > >>> should really do better with testing it or deprecate it and remove it > >>> (which would save us some complications in the code). > >>> > >>> I would be slightly in favor of removing it (code simplicity, less options > >>> to configure for admin, less options to test for us, some users I've come > >>> across actually were not quite sure why they are using it - they just > >>> thought it looks safer). > > > > Hmm... FYI, I hope to be able to bring on line automated testing for > > ext4 later this summer (there's a testing person at Google is has > > signed up to work on setting this up as his 20% project). The test > > matrix that I have him included data=journal, so we will be getting > > better testing in the near future. > > > > At least historically, data=journalling was the *simpler* case, and > > was the first thing supported by ext4. (data=ordered required revoke > > handling which didn't land for six months or so). So I'm not really > > that convinced that removing really buys us that much code > > simplification. > > > > That being siad, it is true that data=journalled isn't necessarily > > faster. For heavy disk-bound workloads, it can be slower. So I can > > imagine adding some documentation that warns people not to use > > data=journal unless they really know what they are doing, but at least > > personally, I'm a bit reluctant to dispense with a bug report like > > this by saying, "oh, that feature should be deprecated". > > I suppose I should chime in here, since I'm the one who (potentially > incorrectly) thinks I should be using data=journalled mode. > > My basic impression is that the use of "data=journalled" can help > reduce the risk (slightly) of serious corruption to some kinds of > databases when the application does not provide appropriate syncs > or journalling on its own (IE: such as text-based Wiki database files). It depends on the way such programs update the database files. But generally yeas, data=journal provides a bit more guarantees than other journaling modes - see below. > Please correct me if this is horribly horribly wrong: > > no journal: > Nothing is journalled > + Very fast. > + Works well for filesystems that are "mkfs"ed on every boot > - Have to fsck after every reboot Fsck is needed only after a crash / hard powerdown. Otherwise completely correct. Plus you always have a possibility of exposing uninitialized (potentially sensitive) data after a fsck. Actually, normal desktop might be quite happy with non-journaled filesystem when fsck is fask enough. > data=writeback: > Metadata is journalled, data (to allocated extents) may be written > before or after the metadata is updated with a new file size. > + Fast (not as fast as unjournalled) > + No need to "fsck" after a hard power-down > - A crash or power failure in the middle of a write could leave > old data on disk at the end of a file. If security labeling > such as SELinux is enabled, this could "contaminate" a file with > data from a deleted file that was at a higher sensitivity. > Log files (including binary database replication logs) may be > effectively corrupted as a result. Correct. > data=ordered: > Data appended to a file will be written before the metadata > extending the length of the file is written, and in certain cases > the data will be written before file renames (partial ordering), > but the data itself is unjournalled, and may be only partially > complete for updates. > + Does not write data to the media twice > + A crash or power failure will not leave old uninitialized data > in files. > - Data writes to files may only partially complete in the event > of a crash. No problems for logfiles, or self-journalled > application databases, but others may experience partial writes > in the event of a crash and need recovery. Correct, one should also note that noone guarantees order in which data hits the disk - i.e. when you do write(f,"a"); write(f,"b"); and these are overwrites it may happen that "b" is written while "a" is not. > data=journalled: > Data and metadata are both journalled, meaning that a given data > write will either complete or it will never occur, although the > precise ordering is not guaranteed. This also implies all of the > data<=>metadata guarantees of data=ordered. > + Direct IO data writes are effectively "atomic", resulting in > less likelihood of data loss for application databases which do > not do their own journalling. This means that a power failure > or system crash will not result in a partially-complete write. Well, direct IO is atomic in data=journal the same way as in data=ordered. It can happen only half of direct IO write is done when you hit power button at the right moment - note this holds for overwrites. Extending writes or writes to holes are all-or-nothing for ext4 (again both in data=journal and data=ordered mode). > - Cached writes are not atomic > + For small cached file writes (of only a few filesystem pages) > there is a good chance that kernel writeback will queue the > entire write as a single I/O and it will be "protected" as a > result. This helps reduce the chance of serious damage to some > text-based database files (such as those for some Wikis), but > is obviously not a guarantee. Page sized and page aligned writes are atomic (in both data=journal and data=ordered modes). When a write spans multiple pages, there are chances the writes will be merged in a single transaction but no guarantees as you properly write. > - This writes all data to the block device twice (once to the FS > journal and once to the data blocks). This may be especially bad > for write-limited Flash-backed devices. Correct. To sum up, the only additional guarantee data=journal offers against data=ordered is a total ordering of all IO operations. That is, if you do a sequence of data and metadata operations, then you are guaranteed that after a crash you will see the filesystem in a state corresponding exactly to your sequence terminated at some (arbitrary) point. Data writes are disassembled into page-sized & page-aligned sequence of writes for purpose of this model... Honza
On Tue, 2011-06-28 at 11:36 +0200, Jan Kara wrote: > On Mon 27-06-11 23:21:17, Moffett, Kyle D wrote: [...] > > Please correct me if this is horribly horribly wrong: > > > > no journal: > > Nothing is journalled > > + Very fast. > > + Works well for filesystems that are "mkfs"ed on every boot > > - Have to fsck after every reboot > Fsck is needed only after a crash / hard powerdown. Otherwise completely > correct. Plus you always have a possibility of exposing uninitialized > (potentially sensitive) data after a fsck. > > Actually, normal desktop might be quite happy with non-journaled filesystem > when fsck is fask enough. [...] With no journal, there is a fair risk that fsck cannot recover the filesystem automatically (let alone the actual data). And normal users should never have to suffer questions from fsck. Ben.
> > My basic impression is that the use of "data=journalled" can help > > reduce the risk (slightly) of serious corruption to some kinds of > > databases when the application does not provide appropriate syncs > > or journalling on its own (IE: such as text-based Wiki database files). Yes, although if the application has index files that have to be updated at the same time, there is no guarantee that the changes that survive after a system failure (either a crash or a power fail), unless the application is doing proper application-level journalling or some other structured. > To sum up, the only additional guarantee data=journal offers against > data=ordered is a total ordering of all IO operations. That is, if you do a > sequence of data and metadata operations, then you are guaranteed that > after a crash you will see the filesystem in a state corresponding exactly > to your sequence terminated at some (arbitrary) point. Data writes are > disassembled into page-sized & page-aligned sequence of writes for purpose > of this model... data=journal can also make the fsync() operation faster, since it will involver fewer seeks (although it will require a greater write bandwidth). Depending on the write bandwidth, you really need to benchmark things to be sure, though. - Ted -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
This is really helpful to me, but it's deviated a bit from solving the original bug. Based on the last log that I generated showing that the error occurs in journal_stop(), what else should I be testing? Further discussion of the exact behavior of data-journalling below: On Jun 28, 2011, at 05:36, Jan Kara wrote: > On Mon 27-06-11 23:21:17, Moffett, Kyle D wrote: >> On Jun 27, 2011, at 12:01, Ted Ts'o wrote: >>> That being siad, it is true that data=journalled isn't necessarily >>> faster. For heavy disk-bound workloads, it can be slower. So I can >>> imagine adding some documentation that warns people not to use >>> data=journal unless they really know what they are doing, but at least >>> personally, I'm a bit reluctant to dispense with a bug report like >>> this by saying, "oh, that feature should be deprecated". >> >> I suppose I should chime in here, since I'm the one who (potentially >> incorrectly) thinks I should be using data=journalled mode. >> >> Please correct me if this is horribly horribly wrong: >> >> [...] >> >> no journal: >> Nothing is journalled >> + Very fast. >> + Works well for filesystems that are "mkfs"ed on every boot >> - Have to fsck after every reboot > > Fsck is needed only after a crash / hard powerdown. Otherwise completely > correct. Plus you always have a possibility of exposing uninitialized > (potentially sensitive) data after a fsck. Yes, sorry, I dropped the word "hard" from "hard reboot" while editing... oops. > Actually, normal desktop might be quite happy with non-journaled filesystem > when fsck is fask enough. No, because fsck can occasionally fail on a non-journalled filesystem, and then the Joe user is sitting there staring at an unhappy console prompt with a lot of cryptic error messages. It's also very bad for any kind of embedded or server environment that might need to come back up headless. >> data=ordered: >> Data appended to a file will be written before the metadata >> extending the length of the file is written, and in certain cases >> the data will be written before file renames (partial ordering), >> but the data itself is unjournalled, and may be only partially >> complete for updates. >> + Does not write data to the media twice >> + A crash or power failure will not leave old uninitialized data >> in files. >> - Data writes to files may only partially complete in the event >> of a crash. No problems for logfiles, or self-journalled >> application databases, but others may experience partial writes >> in the event of a crash and need recovery. > > Correct, one should also note that noone guarantees order in which data > hits the disk - i.e. when you do write(f,"a"); write(f,"b"); and these are > overwrites it may happen that "b" is written while "a" is not. Yes, right, I should have mentioned that too. If a program wants data-level ordering then it must issue an fsync() or fdatasync(). Just to confirm, an file write in data=ordered mode can be only partially written during a hard shutdown: char a[512] = "aaaaaaaaaaaaaaa"...; char b[512] = "bbbbbbbbbbbbbbb"...; write(fd, a, 512); fsync(fd); write(fd, b, 512); <== Hard poweroff here fsync(fd); The data on disk could contain any mix of "b"s and "a"s, and possibly even garbage data depending on the operation of the disk firmware, correct? >> data=journalled: >> Data and metadata are both journalled, meaning that a given data >> write will either complete or it will never occur, although the >> precise ordering is not guaranteed. This also implies all of the >> data<=>metadata guarantees of data=ordered. >> + Direct IO data writes are effectively "atomic", resulting in >> less likelihood of data loss for application databases which do >> not do their own journalling. This means that a power failure >> or system crash will not result in a partially-complete write. > > Well, direct IO is atomic in data=journal the same way as in data=ordered. > It can happen only half of direct IO write is done when you hit power > button at the right moment - note this holds for overwrites. Extending > writes or writes to holes are all-or-nothing for ext4 (again both in > data=journal and data=ordered mode). My impression of journalled data was that a single-sector write would be written checksummed into the journal and then later into the actual filesystem, so it would either complete (IE: journal entry checksum is OK and it gets replayed after a crash) or it would not (IE: journal entry does not checksum and therefore the later write never happened and the entry is not replayed). Where is my mental model wrong? >> - Cached writes are not atomic >> + For small cached file writes (of only a few filesystem pages) >> there is a good chance that kernel writeback will queue the >> entire write as a single I/O and it will be "protected" as a >> result. This helps reduce the chance of serious damage to some >> text-based database files (such as those for some Wikis), but >> is obviously not a guarantee. > Page sized and page aligned writes are atomic (in both data=journal and > data=ordered modes). When a write spans multiple pages, there are chances > the writes will be merged in a single transaction but no guarantees as you > properly write. I don't know that our definitions of "atomic write" are quite the same... I'm assuming that filesystem "atomic write" means that even if the disk itself does not guarantee that a single write will either complete or it will be discarded, then the filesystem will provide that guarantee. Cheers, Kyle Moffett -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Jun 28, 2011, at 10:16, Ted Ts'o wrote: >>> My basic impression is that the use of "data=journalled" can help >>> reduce the risk (slightly) of serious corruption to some kinds of >>> databases when the application does not provide appropriate syncs >>> or journalling on its own (IE: such as text-based Wiki database files). > > Yes, although if the application has index files that have to be > updated at the same time, there is no guarantee that the changes that > survive after a system failure (either a crash or a power fail), > unless the application is doing proper application-level journalling > or some other structured. Manually rebuilding application indexes and clearing out caches is fine; with a badly written application I'd have to do that anyways. I just want to reduce the risk that I actually corrupt data, and it sounds like that's what data-journalling will help with. >> To sum up, the only additional guarantee data=journal offers against >> data=ordered is a total ordering of all IO operations. That is, if you do a >> sequence of data and metadata operations, then you are guaranteed that >> after a crash you will see the filesystem in a state corresponding exactly >> to your sequence terminated at some (arbitrary) point. Data writes are >> disassembled into page-sized & page-aligned sequence of writes for purpose >> of this model... > > data=journal can also make the fsync() operation faster, since it will > involver fewer seeks (although it will require a greater write > bandwidth). Depending on the write bandwidth, you really need to > benchmark things to be sure, though. Hm, so this would actually be very beneficial for a mail spool directory then, because mail servers are supposed to fsync each email received in order to guarantee that it will not be lost before it acknowledges receipt to the SMTP client. Thanks again! Cheers, Kyle Moffett -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Tue 28-06-11 14:30:55, Moffett, Kyle D wrote: > This is really helpful to me, but it's deviated a bit from solving > the original bug. Based on the last log that I generated showing that > the error occurs in journal_stop(), what else should I be testing? I was looking at it for a while but so far I have no idea... > Further discussion of the exact behavior of data-journalling below: > On Jun 28, 2011, at 05:36, Jan Kara wrote: > > On Mon 27-06-11 23:21:17, Moffett, Kyle D wrote: > > > Actually, normal desktop might be quite happy with non-journaled filesystem > > when fsck is fask enough. > > No, because fsck can occasionally fail on a non-journalled filesystem, and > then the Joe user is sitting there staring at an unhappy console prompt with > a lot of cryptic error messages. > > It's also very bad for any kind of embedded or server environment that might > need to come back up headless. OK, I agree. > >> data=ordered: > >> Data appended to a file will be written before the metadata > >> extending the length of the file is written, and in certain cases > >> the data will be written before file renames (partial ordering), > >> but the data itself is unjournalled, and may be only partially > >> complete for updates. > >> + Does not write data to the media twice > >> + A crash or power failure will not leave old uninitialized data > >> in files. > >> - Data writes to files may only partially complete in the event > >> of a crash. No problems for logfiles, or self-journalled > >> application databases, but others may experience partial writes > >> in the event of a crash and need recovery. > > > > Correct, one should also note that noone guarantees order in which data > > hits the disk - i.e. when you do write(f,"a"); write(f,"b"); and these are > > overwrites it may happen that "b" is written while "a" is not. > > Yes, right, I should have mentioned that too. If a program wants > data-level ordering then it must issue an fsync() or fdatasync(). > > Just to confirm, an file write in data=ordered mode can be only > partially written during a hard shutdown: > char a[512] = "aaaaaaaaaaaaaaa"...; > char b[512] = "bbbbbbbbbbbbbbb"...; > write(fd, a, 512); > fsync(fd); > write(fd, b, 512); <== Hard poweroff here > fsync(fd); > > The data on disk could contain any mix of "b"s and "a"s, and possibly > even garbage data depending on the operation of the disk firmware, > correct? Correct. > >> data=journalled: > >> Data and metadata are both journalled, meaning that a given data > >> write will either complete or it will never occur, although the > >> precise ordering is not guaranteed. This also implies all of the > >> data<=>metadata guarantees of data=ordered. > >> + Direct IO data writes are effectively "atomic", resulting in > >> less likelihood of data loss for application databases which do > >> not do their own journalling. This means that a power failure > >> or system crash will not result in a partially-complete write. > > > > Well, direct IO is atomic in data=journal the same way as in data=ordered. > > It can happen only half of direct IO write is done when you hit power > > button at the right moment - note this holds for overwrites. Extending > > writes or writes to holes are all-or-nothing for ext4 (again both in > > data=journal and data=ordered mode). > > My impression of journalled data was that a single-sector write would > be written checksummed into the journal and then later into the actual > filesystem, so it would either complete (IE: journal entry checksum is > OK and it gets replayed after a crash) or it would not (IE: journal > entry does not checksum and therefore the later write never happened > and the entry is not replayed). Umm, right. This is true. That's another guarantee of data=journal mode I didn't think of. > >> - Cached writes are not atomic > >> + For small cached file writes (of only a few filesystem pages) > >> there is a good chance that kernel writeback will queue the > >> entire write as a single I/O and it will be "protected" as a > >> result. This helps reduce the chance of serious damage to some > >> text-based database files (such as those for some Wikis), but > >> is obviously not a guarantee. > > Page sized and page aligned writes are atomic (in both data=journal and > > data=ordered modes). When a write spans multiple pages, there are chances > > the writes will be merged in a single transaction but no guarantees as you > > properly write. > > I don't know that our definitions of "atomic write" are quite the same... > > I'm assuming that filesystem "atomic write" means that even if the disk > itself does not guarantee that a single write will either complete or it > will be discarded, then the filesystem will provide that guarantee. OK. There are different levels of "disk does not guarantee atomic writes" though. E.g. flash disks don't guarantee atomic writes but even more they actually corrupt unrelated blocks on power failure so any filesystem is actually screwed on power failure. For standard rotating drives I'd rely on the drive being able to write a full fs block (4k) although I agree noone really guarantees this. Honza
On Jun 28, 2011, at 18:57, Jan Kara wrote: > On Tue 28-06-11 14:30:55, Moffett, Kyle D wrote: >> On Jun 28, 2011, at 05:36, Jan Kara wrote: >>> Well, direct IO is atomic in data=journal the same way as in data=ordered. >>> It can happen only half of direct IO write is done when you hit power >>> button at the right moment - note this holds for overwrites. Extending >>> writes or writes to holes are all-or-nothing for ext4 (again both in >>> data=journal and data=ordered mode). >> >> My impression of journalled data was that a single-sector write would >> be written checksummed into the journal and then later into the actual >> filesystem, so it would either complete (IE: journal entry checksum is >> OK and it gets replayed after a crash) or it would not (IE: journal >> entry does not checksum and therefore the later write never happened >> and the entry is not replayed). > > Umm, right. This is true. That's another guarantee of data=journal mode I > didn't think of. Ok, that's what I had hoped was the case. That doesn't help much for overwrites of variable-length data (EG: text files), but it does help protect stuff like MySQL MyISAM (which does not do journalling). It's probably unnecessary for MySQL InnoDB, which *does* have its own journal. >>> Page sized and page aligned writes are atomic (in both data=journal and >>> data=ordered modes). When a write spans multiple pages, there are chances >>> the writes will be merged in a single transaction but no guarantees as you >>> properly write. >> >> I don't know that our definitions of "atomic write" are quite the same... >> >> I'm assuming that filesystem "atomic write" means that even if the disk >> itself does not guarantee that a single write will either complete or it >> will be discarded, then the filesystem will provide that guarantee. > > OK. There are different levels of "disk does not guarantee atomic writes" > though. E.g. flash disks don't guarantee atomic writes but even more they > actually corrupt unrelated blocks on power failure so any filesystem is > actually screwed on power failure. For standard rotating drives I'd rely on > the drive being able to write a full fs block (4k) although I agree noone > really guarantees this. Well, I've seen a study somewhere that some spinning media actually *can* tend to corrupt a nearby sector or two during a power failure, depending on exactly what the input voltage does. The better ones certainly have a voltage monitor that automatically cuts power to the heads when it goes below a critical level. And the better Flash-based media actually *do* provide atomic write guarantees due to the wear-levelling and flash-remapping engine. In order to protect their mapping table metadata and avoid very large write amplification they will use a system similar to a log-structured filesystem to accumulate a bunch of small random writes into one larger write. Since they're always writing into empty space and then doing an atomic metadata update, their writes are always effectively atomic, even for data. My informal testing of the Intel X-18M drives seems to indicate that they work that way. Cheers, Kyle Moffett -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Ping? Any more ideas for debugging this issue? I can still trigger it on my VM snapshot very easily, so if you have anything you think I should test I would be very happy to give it a shot. On Jun 24, 2011, at 16:51, Kyle Moffett wrote: > On Jun 24, 2011, at 16:02, Jan Kara wrote: >> On Fri 24-06-11 11:03:52, Moffett, Kyle D wrote: >>> On Jun 24, 2011, at 09:46, Jan Kara wrote: >>>> On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: >>>>> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this >>>>> one: >>>>> >>>>> J_ASSERT(commit_transaction->t_nr_buffers <= >>>>> commit_transaction->t_outstanding_credits); >>>> >>>> The trouble is that the problem is likely in some journal list shuffling >>>> code because if just some operation wrongly estimated the number of needed >>>> buffers, we'd fail the assertion in jbd2_journal_dirty_metadata(): >>>> J_ASSERT_JH(jh, handle->h_buffer_credits > 0); >>> >>> Hmm, ok... I'm also going to turn that failing J_ASSERT() into a WARN_ON() >>> just to see how much further it gets. I have an easy script to recreate this >>> data volume even if it gets totally hosed anyways, so... >> >> OK, we'll see what happens. > > Ok, status update here: > > I applied a modified version of your patch that prints out the values of both > t_outstanding_credits and t_nr_buffers when the assertion triggers. I replaced > the J_ASSERT() that was failing with the exact same WARN_ON() trigger too. > > The end result is that postfix successfully finished delivering all the emails. > Afterwards I unmounted both filesystems and ran "fsck -fy" on them, it reported > no errors at all. > > Looking through the log, the filesystem with the issues is the 32MB one mounted > on /var/lib/postfix: > total 61 > drwxr-x--- 3 postfix postfix 1024 Jun 16 21:02 . > drwxr-xr-x 46 root root 4096 Jun 20 17:19 .. > d--------- 2 root root 12288 Jun 16 18:35 lost+found > -rw------- 1 postfix postfix 33 Jun 24 16:34 master.lock > -rw------- 1 postfix postfix 1024 Jun 24 16:44 prng_exch > -rw------- 1 postfix postfix 2048 Jun 24 16:34 smtpd_scache.db > -rw------- 1 postfix postfix 41984 Jun 24 16:36 smtp_scache.db > > In particular, it's the tlsmgr program accessing the smtp_scache file when it > dies. > > Full log below. > > Cheers, > Kyle Moffett > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385234] transaction->t_outstanding_credits = 8 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385247] transaction->t_nr_buffers = 9 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385251] ------------[ cut here ]------------ > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385278] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385287] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat nf_conntrac > Jun 24 16:36:05 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385440] Pid: 3817, comm: tlsmgr Not tainted 2.6.32-5-xen-amd64 #1 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385445] Call Trace: > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385458] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385467] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385477] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385486] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385505] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385517] [<ffffffffa0060949>] ? ext4_journalled_write_end+0x160/0x19a [ext4] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385633] [<ffffffffa00857c6>] ? ext4_xattr_get+0x1fa/0x27c [ext4] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385643] [<ffffffff810b5e91>] ? generic_file_buffered_write+0x18d/0x278 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385650] [<ffffffff810b632d>] ? __generic_file_aio_write+0x25f/0x293 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385659] [<ffffffffa0032d42>] ? jbd2_journal_stop+0x24a/0x25d [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385669] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385674] [<ffffffff810b63ba>] ? generic_file_aio_write+0x59/0x9f > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385682] [<ffffffff810efa46>] ? do_sync_write+0xce/0x113 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385694] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385701] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385709] [<ffffffff81102492>] ? notify_change+0x2b3/0x2c5 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385715] [<ffffffff810f0398>] ? vfs_write+0xa9/0x102 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385720] [<ffffffff810f0448>] ? sys_pwrite64+0x57/0x77 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385726] [<ffffffff810ef04d>] ? sys_ftruncate+0x112/0x11d > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385732] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385737] ---[ end trace 2c615eb111c993ca ]--- > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385782] transaction->t_outstanding_credits = 8 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385788] transaction->t_nr_buffers = 9 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385793] ------------[ cut here ]------------ > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385804] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385815] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat nf_conntrac > Jun 24 16:36:05 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386041] Pid: 3817, comm: tlsmgr Tainted: G W 2.6.32-5-xen-amd64 #1 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386046] Call Trace: > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386055] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386064] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386071] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386077] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386087] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386098] [<ffffffffa0033cd6>] ? jbd2_journal_start+0x96/0xc6 [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386113] [<ffffffffa0070df6>] ? ext4_force_commit+0xa4/0xb3 [ext4] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386126] [<ffffffffa0058a37>] ? ext4_sync_file+0x8f/0x25c [ext4] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386138] [<ffffffff8110ccd4>] ? vfs_fsync_range+0x73/0x9e > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386146] [<ffffffff8110cd7e>] ? do_fsync+0x28/0x39 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386153] [<ffffffff8110cd9d>] ? sys_fdatasync+0xe/0x13 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386163] [<ffffffff8130d89a>] ? error_exit+0x2a/0x60 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386170] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386178] [<ffffffff810092eb>] ? hypercall_page+0x2eb/0x1001 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386185] ---[ end trace 2c615eb111c993cb ]--- > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386243] transaction->t_outstanding_credits = 8 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386249] transaction->t_nr_buffers = 9 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386253] ------------[ cut here ]------------ > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386263] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/commit.c:538 jbd2_journal_commit_transaction+0x574/0x118b [jbd2]() > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386311] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat nf_conntrac > Jun 24 16:36:05 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386452] Pid: 992, comm: jbd2/dm-23-8 Tainted: G W 2.6.32-5-xen-amd64 #1 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386457] Call Trace: > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386466] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386475] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386483] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386492] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386500] [<ffffffff8130bf48>] ? thread_return+0x79/0xe0 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386506] [<ffffffff8100e629>] ? xen_force_evtchn_callback+0x9/0xa > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386512] [<ffffffff8100ece2>] ? check_events+0x12/0x20 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386519] [<ffffffff8130d2e2>] ? _spin_unlock_irqrestore+0xd/0xe > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386560] [<ffffffff8105b8c8>] ? try_to_del_timer_sync+0x63/0x6c > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386572] [<ffffffffa003a98b>] ? kjournald2+0xbe/0x206 [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386578] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386587] [<ffffffffa003a8cd>] ? kjournald2+0x0/0x206 [jbd2] > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386592] [<ffffffff81065c39>] ? kthread+0x79/0x81 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386599] [<ffffffff81012baa>] ? child_rip+0xa/0x20 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386604] [<ffffffff81011d61>] ? int_ret_from_sys_call+0x7/0x1b > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386610] [<ffffffff8101251d>] ? retint_restore_args+0x5/0x6 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386616] [<ffffffff81012ba0>] ? child_rip+0x0/0x20 > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386620] ---[ end trace 2c615eb111c993cc ]--- > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124954] transaction->t_outstanding_credits = 9 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124967] transaction->t_nr_buffers = 10 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124971] ------------[ cut here ]------------ > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124998] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125007] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat nf_conntrac > Jun 24 16:36:07 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125158] Pid: 3817, comm: tlsmgr Tainted: G W 2.6.32-5-xen-amd64 #1 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125164] Call Trace: > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125174] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125183] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125194] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125203] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125222] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125338] [<ffffffffa0060949>] ? ext4_journalled_write_end+0x160/0x19a [ext4] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125351] [<ffffffffa00857c6>] ? ext4_xattr_get+0x1fa/0x27c [ext4] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125361] [<ffffffff810b5e91>] ? generic_file_buffered_write+0x18d/0x278 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125368] [<ffffffff810b632d>] ? __generic_file_aio_write+0x25f/0x293 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125377] [<ffffffffa0032d42>] ? jbd2_journal_stop+0x24a/0x25d [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125385] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125391] [<ffffffff810b63ba>] ? generic_file_aio_write+0x59/0x9f > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125398] [<ffffffff810efa46>] ? do_sync_write+0xce/0x113 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125410] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125418] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125426] [<ffffffff81102492>] ? notify_change+0x2b3/0x2c5 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125432] [<ffffffff810f0398>] ? vfs_write+0xa9/0x102 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125437] [<ffffffff810f0448>] ? sys_pwrite64+0x57/0x77 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125443] [<ffffffff810ef04d>] ? sys_ftruncate+0x112/0x11d > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125449] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125454] ---[ end trace 2c615eb111c993cd ]--- > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180777] transaction->t_outstanding_credits = 9 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180787] transaction->t_nr_buffers = 10 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180792] ------------[ cut here ]------------ > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180810] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180819] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat nf_conntrac > Jun 24 16:36:07 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180969] Pid: 3817, comm: tlsmgr Tainted: G W 2.6.32-5-xen-amd64 #1 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180975] Call Trace: > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180983] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180992] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180999] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181006] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181015] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181024] [<ffffffffa0033cd6>] ? jbd2_journal_start+0x96/0xc6 [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181083] [<ffffffffa0070df6>] ? ext4_force_commit+0xa4/0xb3 [ext4] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181094] [<ffffffffa0058a37>] ? ext4_sync_file+0x8f/0x25c [ext4] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181104] [<ffffffff8110ccd4>] ? vfs_fsync_range+0x73/0x9e > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181110] [<ffffffff8110cd7e>] ? do_fsync+0x28/0x39 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181115] [<ffffffff8110cd9d>] ? sys_fdatasync+0xe/0x13 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181125] [<ffffffff8130d89a>] ? error_exit+0x2a/0x60 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181131] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181137] [<ffffffff810092eb>] ? hypercall_page+0x2eb/0x1001 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181142] ---[ end trace 2c615eb111c993ce ]--- > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181160] transaction->t_outstanding_credits = 9 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181164] transaction->t_nr_buffers = 10 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181168] ------------[ cut here ]------------ > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181176] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/commit.c:538 jbd2_journal_commit_transaction+0x574/0x118b [jbd2]() > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181185] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat nf_conntrac > Jun 24 16:36:07 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181368] Pid: 992, comm: jbd2/dm-23-8 Tainted: G W 2.6.32-5-xen-amd64 #1 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181374] Call Trace: > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181383] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181393] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181401] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181409] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181418] [<ffffffff8130bf48>] ? thread_return+0x79/0xe0 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181424] [<ffffffff8100e629>] ? xen_force_evtchn_callback+0x9/0xa > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181430] [<ffffffff8100ece2>] ? check_events+0x12/0x20 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181436] [<ffffffff8130d2e2>] ? _spin_unlock_irqrestore+0xd/0xe > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181445] [<ffffffff8105b8c8>] ? try_to_del_timer_sync+0x63/0x6c > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181455] [<ffffffffa003a98b>] ? kjournald2+0xbe/0x206 [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181461] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181470] [<ffffffffa003a8cd>] ? kjournald2+0x0/0x206 [jbd2] > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181475] [<ffffffff81065c39>] ? kthread+0x79/0x81 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181482] [<ffffffff81012baa>] ? child_rip+0xa/0x20 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181487] [<ffffffff81011d61>] ? int_ret_from_sys_call+0x7/0x1b > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181493] [<ffffffff8101251d>] ? retint_restore_args+0x5/0x6 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181499] [<ffffffff81012ba0>] ? child_rip+0x0/0x20 > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181503] ---[ end trace 2c615eb111c993cf ]--- -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Hi, On Fri 26-08-11 16:03:32, Moffett, Kyle D wrote: > Ping? > > Any more ideas for debugging this issue? Sorry for not getting to you earlier. > I can still trigger it on my VM snapshot very easily, so if you have anything > you think I should test I would be very happy to give it a shot. OK, so in the meantime I found a bug in data=journal code which could be related to your problem. It is fixed by commit 2d859db3e4a82a365572592d57624a5f996ed0ec which is in 3.1-rc1. Have you tried that or newer kernel as well? If the problem still is not fixed, I can provide some debugging patch to you. We spoke with Josef Bacik how errors like yours could happen so I have some places to watch... Honza > On Jun 24, 2011, at 16:51, Kyle Moffett wrote: > > On Jun 24, 2011, at 16:02, Jan Kara wrote: > >> On Fri 24-06-11 11:03:52, Moffett, Kyle D wrote: > >>> On Jun 24, 2011, at 09:46, Jan Kara wrote: > >>>> On Thu 23-06-11 16:19:08, Moffett, Kyle D wrote: > >>>>> Besides which, line 534 in the Debian 2.6.32 kernel I am using is this > >>>>> one: > >>>>> > >>>>> J_ASSERT(commit_transaction->t_nr_buffers <= > >>>>> commit_transaction->t_outstanding_credits); > >>>> > >>>> The trouble is that the problem is likely in some journal list shuffling > >>>> code because if just some operation wrongly estimated the number of needed > >>>> buffers, we'd fail the assertion in jbd2_journal_dirty_metadata(): > >>>> J_ASSERT_JH(jh, handle->h_buffer_credits > 0); > >>> > >>> Hmm, ok... I'm also going to turn that failing J_ASSERT() into a WARN_ON() > >>> just to see how much further it gets. I have an easy script to recreate this > >>> data volume even if it gets totally hosed anyways, so... > >> > >> OK, we'll see what happens. > > > > Ok, status update here: > > > > I applied a modified version of your patch that prints out the values of both > > t_outstanding_credits and t_nr_buffers when the assertion triggers. I replaced > > the J_ASSERT() that was failing with the exact same WARN_ON() trigger too. > > > > The end result is that postfix successfully finished delivering all the emails. > > Afterwards I unmounted both filesystems and ran "fsck -fy" on them, it reported > > no errors at all. > > > > Looking through the log, the filesystem with the issues is the 32MB one mounted > > on /var/lib/postfix: > > total 61 > > drwxr-x--- 3 postfix postfix 1024 Jun 16 21:02 . > > drwxr-xr-x 46 root root 4096 Jun 20 17:19 .. > > d--------- 2 root root 12288 Jun 16 18:35 lost+found > > -rw------- 1 postfix postfix 33 Jun 24 16:34 master.lock > > -rw------- 1 postfix postfix 1024 Jun 24 16:44 prng_exch > > -rw------- 1 postfix postfix 2048 Jun 24 16:34 smtpd_scache.db > > -rw------- 1 postfix postfix 41984 Jun 24 16:36 smtp_scache.db > > > > In particular, it's the tlsmgr program accessing the smtp_scache file when it > > dies. > > > > Full log below. > > > > Cheers, > > Kyle Moffett > > > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385234] transaction->t_outstanding_credits = 8 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385247] transaction->t_nr_buffers = 9 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385251] ------------[ cut here ]------------ > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385278] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385287] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat n > f_conntrac > > Jun 24 16:36:05 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385440] Pid: 3817, comm: tlsmgr Not tainted 2.6.32-5-xen-amd64 #1 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385445] Call Trace: > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385458] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385467] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385477] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385486] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385505] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385517] [<ffffffffa0060949>] ? ext4_journalled_write_end+0x160/0x19a [ext4] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385633] [<ffffffffa00857c6>] ? ext4_xattr_get+0x1fa/0x27c [ext4] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385643] [<ffffffff810b5e91>] ? generic_file_buffered_write+0x18d/0x278 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385650] [<ffffffff810b632d>] ? __generic_file_aio_write+0x25f/0x293 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385659] [<ffffffffa0032d42>] ? jbd2_journal_stop+0x24a/0x25d [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385669] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385674] [<ffffffff810b63ba>] ? generic_file_aio_write+0x59/0x9f > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385682] [<ffffffff810efa46>] ? do_sync_write+0xce/0x113 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385694] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385701] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385709] [<ffffffff81102492>] ? notify_change+0x2b3/0x2c5 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385715] [<ffffffff810f0398>] ? vfs_write+0xa9/0x102 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385720] [<ffffffff810f0448>] ? sys_pwrite64+0x57/0x77 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385726] [<ffffffff810ef04d>] ? sys_ftruncate+0x112/0x11d > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385732] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385737] ---[ end trace 2c615eb111c993ca ]--- > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385782] transaction->t_outstanding_credits = 8 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385788] transaction->t_nr_buffers = 9 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385793] ------------[ cut here ]------------ > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385804] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.385815] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat n > f_conntrac > > Jun 24 16:36:05 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386041] Pid: 3817, comm: tlsmgr Tainted: G W 2.6.32-5-xen-amd64 #1 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386046] Call Trace: > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386055] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386064] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386071] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386077] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386087] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386098] [<ffffffffa0033cd6>] ? jbd2_journal_start+0x96/0xc6 [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386113] [<ffffffffa0070df6>] ? ext4_force_commit+0xa4/0xb3 [ext4] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386126] [<ffffffffa0058a37>] ? ext4_sync_file+0x8f/0x25c [ext4] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386138] [<ffffffff8110ccd4>] ? vfs_fsync_range+0x73/0x9e > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386146] [<ffffffff8110cd7e>] ? do_fsync+0x28/0x39 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386153] [<ffffffff8110cd9d>] ? sys_fdatasync+0xe/0x13 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386163] [<ffffffff8130d89a>] ? error_exit+0x2a/0x60 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386170] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386178] [<ffffffff810092eb>] ? hypercall_page+0x2eb/0x1001 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386185] ---[ end trace 2c615eb111c993cb ]--- > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386243] transaction->t_outstanding_credits = 8 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386249] transaction->t_nr_buffers = 9 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386253] ------------[ cut here ]------------ > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386263] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/commit.c:538 jbd2_journal_commit_transaction+0x574/0x118b [jbd2]() > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386311] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat n > f_conntrac > > Jun 24 16:36:05 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386452] Pid: 992, comm: jbd2/dm-23-8 Tainted: G W 2.6.32-5-xen-amd64 #1 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386457] Call Trace: > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386466] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386475] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386483] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386492] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386500] [<ffffffff8130bf48>] ? thread_return+0x79/0xe0 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386506] [<ffffffff8100e629>] ? xen_force_evtchn_callback+0x9/0xa > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386512] [<ffffffff8100ece2>] ? check_events+0x12/0x20 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386519] [<ffffffff8130d2e2>] ? _spin_unlock_irqrestore+0xd/0xe > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386560] [<ffffffff8105b8c8>] ? try_to_del_timer_sync+0x63/0x6c > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386572] [<ffffffffa003a98b>] ? kjournald2+0xbe/0x206 [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386578] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386587] [<ffffffffa003a8cd>] ? kjournald2+0x0/0x206 [jbd2] > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386592] [<ffffffff81065c39>] ? kthread+0x79/0x81 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386599] [<ffffffff81012baa>] ? child_rip+0xa/0x20 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386604] [<ffffffff81011d61>] ? int_ret_from_sys_call+0x7/0x1b > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386610] [<ffffffff8101251d>] ? retint_restore_args+0x5/0x6 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386616] [<ffffffff81012ba0>] ? child_rip+0x0/0x20 > > Jun 24 16:36:05 i-38020f57 kernel: [5369326.386620] ---[ end trace 2c615eb111c993cc ]--- > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124954] transaction->t_outstanding_credits = 9 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124967] transaction->t_nr_buffers = 10 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124971] ------------[ cut here ]------------ > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.124998] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125007] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat n > f_conntrac > > Jun 24 16:36:07 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125158] Pid: 3817, comm: tlsmgr Tainted: G W 2.6.32-5-xen-amd64 #1 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125164] Call Trace: > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125174] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125183] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125194] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125203] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125222] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125338] [<ffffffffa0060949>] ? ext4_journalled_write_end+0x160/0x19a [ext4] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125351] [<ffffffffa00857c6>] ? ext4_xattr_get+0x1fa/0x27c [ext4] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125361] [<ffffffff810b5e91>] ? generic_file_buffered_write+0x18d/0x278 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125368] [<ffffffff810b632d>] ? __generic_file_aio_write+0x25f/0x293 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125377] [<ffffffffa0032d42>] ? jbd2_journal_stop+0x24a/0x25d [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125385] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125391] [<ffffffff810b63ba>] ? generic_file_aio_write+0x59/0x9f > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125398] [<ffffffff810efa46>] ? do_sync_write+0xce/0x113 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125410] [<ffffffffa0074c8e>] ? __ext4_journal_stop+0x63/0x69 [ext4] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125418] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125426] [<ffffffff81102492>] ? notify_change+0x2b3/0x2c5 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125432] [<ffffffff810f0398>] ? vfs_write+0xa9/0x102 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125437] [<ffffffff810f0448>] ? sys_pwrite64+0x57/0x77 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125443] [<ffffffff810ef04d>] ? sys_ftruncate+0x112/0x11d > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125449] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.125454] ---[ end trace 2c615eb111c993cd ]--- > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180777] transaction->t_outstanding_credits = 9 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180787] transaction->t_nr_buffers = 10 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180792] ------------[ cut here ]------------ > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180810] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/transaction.c:1329 jbd2_journal_stop+0x189/0x25d [jbd2]() > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180819] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat n > f_conntrac > > Jun 24 16:36:07 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180969] Pid: 3817, comm: tlsmgr Tainted: G W 2.6.32-5-xen-amd64 #1 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180975] Call Trace: > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180983] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180992] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.180999] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181006] [<ffffffff8100eccf>] ? xen_restore_fl_direct_end+0x0/0x1 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181015] [<ffffffffa0032c81>] ? jbd2_journal_stop+0x189/0x25d [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181024] [<ffffffffa0033cd6>] ? jbd2_journal_start+0x96/0xc6 [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181083] [<ffffffffa0070df6>] ? ext4_force_commit+0xa4/0xb3 [ext4] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181094] [<ffffffffa0058a37>] ? ext4_sync_file+0x8f/0x25c [ext4] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181104] [<ffffffff8110ccd4>] ? vfs_fsync_range+0x73/0x9e > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181110] [<ffffffff8110cd7e>] ? do_fsync+0x28/0x39 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181115] [<ffffffff8110cd9d>] ? sys_fdatasync+0xe/0x13 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181125] [<ffffffff8130d89a>] ? error_exit+0x2a/0x60 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181131] [<ffffffff81011b42>] ? system_call_fastpath+0x16/0x1b > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181137] [<ffffffff810092eb>] ? hypercall_page+0x2eb/0x1001 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181142] ---[ end trace 2c615eb111c993ce ]--- > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181160] transaction->t_outstanding_credits = 9 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181164] transaction->t_nr_buffers = 10 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181168] ------------[ cut here ]------------ > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181176] WARNING: at /tmp/kdm-deb-kernel/linux-2.6-2.6.32/debian/build/source_amd64_xen/fs/jbd2/commit.c:538 jbd2_journal_commit_transaction+0x574/0x118b [jbd2]() > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181185] Modules linked in: ip6table_filter ip6_tables act_police cls_flow cls_fw cls_u32 sch_htb sch_hfsc sch_ingress sch_sfq xt_time xt_connlimit xt_realm iptable_raw xt_comment xt_recent xt_policy ipt_ULOG ipt_REJECT ipt_REDIRECT ipt_NETMAP ipt_MASQUERADE ipt_ECN ipt_ecn ipt_CLUSTERIP ipt_ah ipt_addrtype nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda ts_kmp nf_conntrack_amanda nf_conntrack_sane nf_conntrack_tftp nf_conntrack_sip nf_conntrack_proto_sctp nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netlink nf_conntrack_netbios_ns nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp xt_TPROXY nf_tproxy_core xt_tcpmss xt_pkttype xt_physdev xt_owner xt_NFQUEUE xt_NFLOG nfnetlink_log xt_multiport xt_MARK xt_mark xt_mac xt_limit xt_length xt_iprange xt_helper xt_hashlimit xt_DSCP xt_dscp xt_dccp xt_conntrack xt_CONNMARK xt_connmark xt_CLASSIFY ipt_LOG xt_tcpudp xt_state iptable_nat nf_nat n > f_conntrac > > Jun 24 16:36:07 i-38020f57 kernel: k_ipv4 nf_defrag_ipv4 nf_conntrack iptable_mangle nfnetlink iptable_filter ip_tables x_tables ext3 jbd loop snd_pcm snd_timer snd soundcore snd_page_alloc pcspkr evdev ext4 mbcache jbd2 crc16 dm_mod xen_netfront xen_blkfront > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181368] Pid: 992, comm: jbd2/dm-23-8 Tainted: G W 2.6.32-5-xen-amd64 #1 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181374] Call Trace: > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181383] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181393] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181401] [<ffffffff8104ef00>] ? warn_slowpath_common+0x77/0xa3 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181409] [<ffffffffa0034471>] ? jbd2_journal_commit_transaction+0x574/0x118b [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181418] [<ffffffff8130bf48>] ? thread_return+0x79/0xe0 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181424] [<ffffffff8100e629>] ? xen_force_evtchn_callback+0x9/0xa > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181430] [<ffffffff8100ece2>] ? check_events+0x12/0x20 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181436] [<ffffffff8130d2e2>] ? _spin_unlock_irqrestore+0xd/0xe > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181445] [<ffffffff8105b8c8>] ? try_to_del_timer_sync+0x63/0x6c > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181455] [<ffffffffa003a98b>] ? kjournald2+0xbe/0x206 [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181461] [<ffffffff81065f06>] ? autoremove_wake_function+0x0/0x2e > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181470] [<ffffffffa003a8cd>] ? kjournald2+0x0/0x206 [jbd2] > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181475] [<ffffffff81065c39>] ? kthread+0x79/0x81 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181482] [<ffffffff81012baa>] ? child_rip+0xa/0x20 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181487] [<ffffffff81011d61>] ? int_ret_from_sys_call+0x7/0x1b > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181493] [<ffffffff8101251d>] ? retint_restore_args+0x5/0x6 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181499] [<ffffffff81012ba0>] ? child_rip+0x0/0x20 > > Jun 24 16:36:07 i-38020f57 kernel: [5369328.181503] ---[ end trace 2c615eb111c993cf ]--- >
On Aug 30, 2011, at 18:12, Jan Kara wrote: > On Fri 26-08-11 16:03:32, Moffett, Kyle D wrote: >> Ping? >> >> Any more ideas for debugging this issue? > > Sorry for not getting to you earlier. That's ok, I have a workaround so it's been on my back burner for a while. >> I can still trigger it on my VM snapshot very easily, so if you have anything >> you think I should test I would be very happy to give it a shot. > > OK, so in the meantime I found a bug in data=journal code which could be > related to your problem. It is fixed by commit > 2d859db3e4a82a365572592d57624a5f996ed0ec which is in 3.1-rc1. Have you > tried that or newer kernel as well? > > If the problem still is not fixed, I can provide some debugging patch to > you. We spoke with Josef Bacik how errors like yours could happen so I have > some places to watch... I have not tried anything more recent; I'm actually a bit reluctant to move away from the Debian squeeze official kernels since I do need the security updates. I took a quick look and I can't find that function in 2.6.32, so I assume it would be a rather nontrivial back-port. It looks like the relevant code used to be in ext4_clear_inode somewhere? Out of curiosity, what would happen in data=journal mode if you unlinked a file which still had buffers pending? That case does not seem to be handled by that commit you mentioned, was it already handled elsewhere? Thanks again! Cheers, Kyle Moffett -- To unsubscribe from this list: send the line "unsubscribe linux-ext4" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
diff -rupX /crypted/home/jack/.kerndiffexclude linux-2.6.32-SLE11-SP1/fs/jbd2/transaction.c linux-2.6.32-SLE11-SP1-1-jbd2-credits-bug//fs/jbd2/transaction.c --- linux-2.6.32-SLE11-SP1/fs/jbd2/transaction.c 2011-06-23 23:01:55.600988795 +0200 +++ linux-2.6.32-SLE11-SP1-1-jbd2-credits-bug//fs/jbd2/transaction.c 2011-06-24 15:43:40.569213743 +0200 @@ -416,6 +416,7 @@ int jbd2_journal_restart(handle_t *handl spin_lock(&journal->j_state_lock); spin_lock(&transaction->t_handle_lock); transaction->t_outstanding_credits -= handle->h_buffer_credits; + WARN_ON(transaction->t_outstanding_credits < transaction->t_nr_buffers); transaction->t_updates--; if (!transaction->t_updates) @@ -1317,6 +1318,7 @@ int jbd2_journal_stop(handle_t *handle) spin_lock(&journal->j_state_lock); spin_lock(&transaction->t_handle_lock); transaction->t_outstanding_credits -= handle->h_buffer_credits; + WARN_ON(transaction->t_outstanding_credits < transaction->t_nr_buffers); transaction->t_updates--; if (!transaction->t_updates) { wake_up(&journal->j_wait_updates); @@ -1924,6 +1926,7 @@ void __jbd2_journal_file_buffer(struct j return; case BJ_Metadata: transaction->t_nr_buffers++; + WARN_ON(transaction->t_outstanding_credits < transaction->t_nr_buffers); list = &transaction->t_buffers; break; case BJ_Forget: