Severe data corruption with ext4

From: Richard
Date: Fri Mar 20 2009 - 05:44:21 EST

Next message: Miklos Szeredi: "[patch] don't preempt not TASK_RUNNING tasks"
Previous message: Lai Jiangshan: "Re: [PATCH] rcu_barrier VS cpu_hotplug: Ensure callbacks in deadcpu are migrated to online cpu"
Next in thread: Andrew Morton: "Re: Severe data corruption with ext4"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hello, I've already searched the web and the list archives, but
couldn't find anything related, so I decided to post to the LKML.

I am running an up-to-date Arch Linux [1] installation with the stock
kernel ("2.6.28-ARCH"), using ext4 on LUKS on LVM on RAID-1; LUKS was
set up as described here [2], and RAID/LVM was set up following this
howto [3].

[1] Arch Linux: http://www.archlinux.org/
[2] LUKS setup: http://wiki.archlinux.org/index.php/LUKS
[3] RAID/LVM setup:
http://wiki.archlinux.org/index.php/Installing_with_Software_RAID_or_LVM

The system running several days without any problems, last morning I
found some messages in /var/log/errors.log, stating:

----------
Mar 19 08:42:43 bakunin kernel: BUG: scheduling while atomic:
install-info/27020/0x00000002
Mar 19 08:42:48 bakunin kernel: BUG: scheduling while atomic:
kjournald2/2451/0x00000002
----------

repeating the 2nd line 10 more times.

Looking into /var/log/kernel.log, I found the following message:

----------
Mar 19 08:42:43 bakunin kernel: EXT4-fs error (device dm-13):
ext4_mb_generate_buddy: EXT4-fs: group 0: 16470 blocks in bitmap, 4354
in gd
Mar 19 08:42:43 bakunin kernel:
Mar 19 08:42:43 bakunin kernel: BUG: scheduling while atomic:
install-info/27020/0x00000002
Mar 19 08:42:43 bakunin kernel: Modules linked in: it87 hwmon_vid
isofs zlib_inflate ext3 jbd loop ipv6 arc4 ecb snd_seq_oss nvidia(P)
ath5k snd_seq_midi_event snd_seq snd
_seq_device agpgart mac80211 snd_hda_intel led_class snd_pcm_oss
snd_mixer_oss i2c_core k8temp snd_hwdep pcspkr snd_pcm snd_timer snd
snd_page_alloc cfg80211 shpchp pci_ho
tplug r8169 mii sg soundcore wmi evdev thermal processor fan button
battery ac rtc_cmos rtc_core rtc_lib ext4 mbcache jbd2 crc16 aes_i586
aes_generic xts gf128mul dm_crypt
dm_mod raid1 md_mod sd_mod usbhid hid ahci pata_amd pata_acpi
ata_generic libata scsi_mod ohci_hcd ehci_hcd usbcore [last unloaded:
i2c_dev]
Mar 19 08:42:43 bakunin kernel: Pid: 27020, comm: install-info
Tainted: P 2.6.28-ARCH #1
Mar 19 08:42:43 bakunin kernel: Call Trace:
Mar 19 08:42:43 bakunin kernel: [<c0336dc7>] schedule+0x4a7/0x970
Mar 19 08:42:43 bakunin kernel: [<f8bb844d>]
dm_table_unplug_all+0x3d/0x90 [dm_mod]
Mar 19 08:42:43 bakunin kernel: [<c03396d5>] _spin_unlock+0x5/0x20
Mar 19 08:42:43 bakunin kernel: [<c02790df>] vt_console_print+0x23f/0x330
Mar 19 08:42:43 bakunin kernel: [<c014cde1>] getnstimeofday+0x51/0x110
Mar 19 08:42:43 bakunin kernel: [<c03372e1>] io_schedule+0x51/0x90
Mar 19 08:42:43 bakunin kernel: [<c01be315>] sync_buffer+0x35/0x40
Mar 19 08:42:43 bakunin kernel: [<c0337797>] __wait_on_bit+0x47/0x70
Mar 19 08:42:43 bakunin kernel: [<c01be2e0>] sync_buffer+0x0/0x40
Mar 19 08:42:43 bakunin kernel: [<c01be2e0>] sync_buffer+0x0/0x40
Mar 19 08:42:43 bakunin kernel: [<c0337873>] out_of_line_wait_on_bit+0xb3/0xd0
Mar 19 08:42:43 bakunin kernel: [<c0144dd0>] wake_bit_function+0x0/0x70
Mar 19 08:42:43 bakunin kernel: [<c01be28e>] __wait_on_buffer+0x1e/0x30
Mar 19 08:42:43 bakunin kernel: [<c01be8af>] sync_dirty_buffer+0x7f/0xc0
Mar 19 08:42:43 bakunin kernel: [<f941e227>] ext4_commit_super+0x77/0xd0 [ext4]
Mar 19 08:42:43 bakunin kernel: [<f9421fd7>] ext4_handle_error+0x47/0xb0 [ext4]
Mar 19 08:42:43 bakunin kernel: [<c03365f2>] printk+0x17/0x1d
Mar 19 08:42:43 bakunin kernel: [<f9422104>] ext4_error+0x54/0x60 [ext4]
Mar 19 08:42:43 bakunin kernel: [<f942c8cb>]
ext4_mb_init_cache+0x94b/0xb40 [ext4]
Mar 19 08:42:43 bakunin kernel: [<c0173997>] find_or_create_page+0x57/0x90
Mar 19 08:42:43 bakunin kernel: [<f942cd6d>]
ext4_mb_load_buddy+0x2ad/0x2e0 [ext4]
Mar 19 08:42:43 bakunin kernel: [<f942d0da>]
ext4_mb_free_blocks+0x33a/0x760 [ext4]
Mar 19 08:42:43 bakunin kernel: [<c0172b8c>] find_get_page+0x2c/0xd0
Mar 19 08:42:43 bakunin kernel: [<f9412622>]
ext4_mark_iloc_dirty+0x412/0x520 [ext4]
Mar 19 08:42:43 bakunin kernel: [<f940e66b>] ext4_free_blocks+0x5b/0xf0 [ext4]
Mar 19 08:42:43 bakunin kernel: [<f9426dc7>]
ext4_ext_truncate+0x807/0x960 [ext4]
Mar 19 08:42:43 bakunin kernel: [<f9418177>] ext4_truncate+0x147/0x690 [ext4]
Mar 19 08:42:43 bakunin kernel: [<c017c7c1>]
truncate_inode_pages_range+0x191/0x360
Mar 19 08:42:43 bakunin kernel: [<c0183eda>] unmap_mapping_range+0xda/0x280
Mar 19 08:42:43 bakunin kernel: [<c0184266>] vmtruncate+0xc6/0x190
Mar 19 08:42:43 bakunin kernel: [<c01b0c53>] inode_setattr+0x53/0x180
Mar 19 08:42:43 bakunin kernel: [<f9413961>] ext4_setattr+0x241/0x350 [ext4]
Mar 19 08:42:43 bakunin kernel: [<c01a5453>] do_lookup+0x93/0x1e0
Mar 19 08:42:43 bakunin kernel: [<c01b0ec9>] notify_change+0x149/0x340
Mar 19 08:42:43 bakunin kernel: [<c0337e73>] __mutex_lock_slowpath+0x1d3/0x250
Mar 19 08:42:43 bakunin kernel: [<c019c5cc>] do_truncate+0x6c/0x90
Mar 19 08:42:43 bakunin kernel: [<c03396d5>] _spin_unlock+0x5/0x20
Mar 19 08:42:43 bakunin kernel: [<c01aeaee>] __d_lookup+0x10e/0x150
Mar 19 08:42:43 bakunin kernel: [<c01a6a1f>] may_open+0x1bf/0x250
Mar 19 08:42:43 bakunin kernel: [<c01a8ec5>] do_filp_open+0x185/0x860
Mar 19 08:42:43 bakunin kernel: [<c018ec1b>] free_pages_and_swap_cache+0x7b/0xa0
Mar 19 08:42:43 bakunin kernel: [<c03396d5>] _spin_unlock+0x5/0x20
Mar 19 08:42:43 bakunin kernel: [<c019b641>] do_sys_open+0x61/0xf0
Mar 19 08:42:43 bakunin kernel: [<c019b74c>] sys_open+0x2c/0x40
Mar 19 08:42:43 bakunin kernel: [<c0103f0f>] sysenter_do_call+0x12/0x2f
----------

followed by multiple instances of:

----------
Mar 19 08:42:48 bakunin kernel: EXT4-fs error (device dm-13):
mb_free_blocks: double-free of inode 0's block 11457(bit 11457 in
group 0)
Mar 19 08:42:48 bakunin kernel:
Mar 19 08:42:48 bakunin kernel: BUG: scheduling while atomic:
kjournald2/2451/0x00000002
Mar 19 08:42:48 bakunin kernel: Modules linked in: it87 hwmon_vid
isofs zlib_inflate ext3 jbd loop ipv6 arc4 ecb snd_seq_oss nvidia(P)
ath5k snd_seq_midi_event snd_seq snd_seq_device agpgart mac80211
snd_hda_intel led_class snd_pcm_oss snd_mixer_oss i2c_core k8temp
snd_hwdep pcspkr snd_pcm snd_timer snd snd_page_alloc cfg80211 shpchp
pci_hotplug r8169 mii sg soundcore wmi evdev thermal processor fan
button battery ac rtc_cmos rtc_core rtc_lib ext4 mbcache jbd2 crc16
aes_i586 aes_generic xts gf128mul dm_crypt dm_mod raid1 md_mod sd_mod
usbhid hid ahci pata_amd pata_acpi ata_generic libata scsi_mod
ohci_hcd ehci_hcd usbcore [last unloaded: i2c_dev]
Mar 19 08:42:48 bakunin kernel: Pid: 2451, comm: kjournald2 Tainted: P
2.6.28-ARCH #1
Mar 19 08:42:48 bakunin kernel: Call Trace:
Mar 19 08:42:48 bakunin kernel: [<c0336dc7>] schedule+0x4a7/0x970
Mar 19 08:42:48 bakunin kernel: [<f8bb844d>]
dm_table_unplug_all+0x3d/0x90 [dm_mod]
Mar 19 08:42:48 bakunin kernel: [<c0144d9b>] autoremove_wake_function+0x1b/0x50
Mar 19 08:42:48 bakunin kernel: [<c03396d5>] _spin_unlock+0x5/0x20
Mar 19 08:42:48 bakunin kernel: [<c02790df>] vt_console_print+0x23f/0x330
Mar 19 08:42:48 bakunin kernel: [<c014cde1>] getnstimeofday+0x51/0x110
Mar 19 08:42:48 bakunin kernel: [<c03372e1>] io_schedule+0x51/0x90
Mar 19 08:42:48 bakunin kernel: [<c01be315>] sync_buffer+0x35/0x40
Mar 19 08:42:48 bakunin kernel: [<c0337797>] __wait_on_bit+0x47/0x70
Mar 19 08:42:48 bakunin kernel: [<c01be2e0>] sync_buffer+0x0/0x40
Mar 19 08:42:48 bakunin kernel: [<c01be2e0>] sync_buffer+0x0/0x40
Mar 19 08:42:48 bakunin kernel: [<c0337873>] out_of_line_wait_on_bit+0xb3/0xd0
Mar 19 08:42:48 bakunin kernel: [<c0144dd0>] wake_bit_function+0x0/0x70
Mar 19 08:42:48 bakunin kernel: [<c01be28e>] __wait_on_buffer+0x1e/0x30
Mar 19 08:42:48 bakunin kernel: [<c01be8af>] sync_dirty_buffer+0x7f/0xc0
Mar 19 08:42:48 bakunin kernel: [<f941e227>] ext4_commit_super+0x77/0xd0 [ext4]
Mar 19 08:42:48 bakunin kernel: [<f9421fd7>] ext4_handle_error+0x47/0xb0 [ext4]
Mar 19 08:42:48 bakunin kernel: [<c03365f2>] printk+0x17/0x1d
Mar 19 08:42:48 bakunin kernel: [<f9422104>] ext4_error+0x54/0x60 [ext4]
Mar 19 08:42:48 bakunin kernel: [<f942b40c>] mb_free_blocks+0x1dc/0x440 [ext4]
Mar 19 08:42:48 bakunin kernel: [<f943022e>]
release_blocks_on_commit+0xde/0x250 [ext4]
Mar 19 08:42:48 bakunin kernel: [<f93b038c>]
jbd2_journal_commit_transaction+0xf3c/0x1180 [jbd2]
Mar 19 08:42:48 bakunin kernel: [<f93b3dac>] kjournald2+0xac/0x1f0 [jbd2]
Mar 19 08:42:48 bakunin kernel: [<c0144d80>] autoremove_wake_function+0x0/0x50
Mar 19 08:42:48 bakunin kernel: [<f93b3d00>] kjournald2+0x0/0x1f0 [jbd2]
Mar 19 08:42:48 bakunin kernel: [<c0144a89>] kthread+0x39/0x70
Mar 19 08:42:48 bakunin kernel: [<c0144a50>] kthread+0x0/0x70
Mar 19 08:42:48 bakunin kernel: [<c0104d9f>] kernel_thread_helper+0x7/0x18
----------

Using "dmsetup ls", I figured that dm-13 was /usr; so I fsck'd it.
fsck revealed hundreds of errors, which I let "fsck -y" fix automatically.
Now there's plenty (more than 250) of files and directories in /usr/lost+found.

[Annotation: When I now, after a reboot, use "dmsetup ls", /usr is
associated minor number 14, while 13 (which is mentioned in
the error messages above) is associated with /var. I don't know
whether I misread the number/volume in the first place, or if
the enumeration can change after a reboot. However, /var is hosting a
clean filesystem.]

An extended SMART self-test of my hard drives spotted no error messages.

The evening before the errors occured, I ran lm_sensors'
"sensors-detect" script which loaded a couple of modules and stuff.
Don't know if there might be a connection.

Also, every night about 5 minutes past midnight, I get something like
this in my logs:

----------
Mar 19 00:04:51 bakunin kernel: init_special_inode: bogus i_mode (336)
----------

I guess this is caused by some process run by crond, but have not yet
figured out which one spawns/spawned this message.

Annotation:
I remember while my RAID-1 sync'd, when running 3D apps (Quake 3,
glxgears), the system would sometimes suddenly appear to have locked
up, but was working again after some time (like, a minute or so). The
logs showed something like:

----------
Mar 13 01:11:56 bakunin ata4.00: exception Emask 0x0 SAct 0xffff SErr
0x0 action 0x6 frozen
Mar 13 01:11:56 bakunin ata4.00: cmd
61/80:00:92:31:42/02:00:21:00:00/40 tag 0 ncq 327680 out
Mar 13 01:11:56 bakunin res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
Mar 13 01:11:56 bakunin ata4.00: status: { DRDY }
Mar 13 01:11:56 bakunin ata4.00: cmd
61/80:08:12:36:42/00:00:21:00:00/40 tag 1 ncq 65536 out
Mar 13 01:11:56 bakunin res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
Mar 13 01:11:56 bakunin ata4.00: status: { DRDY }
Mar 13 01:11:56 bakunin ata4.00: cmd
61/00:10:92:3a:42/01:00:21:00:00/40 tag 2 ncq 131072 out
Mar 13 01:11:56 bakunin res 40/00:00:00:00:00/00:00:00:00:00/00 Emask
0x4 (timeout)
Mar 13 01:11:56 bakunin ata4.00: status: { DRDY }
----------

Bad cabling, maybe..?
This problem has never, ever occured again after the RAID
synchronization was complete.

lspci output:

----------
00:00.0 RAM memory: nVidia Corporation MCP78S [GeForce 8200] Memory
Controller (rev a2)
00:01.0 ISA bridge: nVidia Corporation MCP78S [GeForce 8200] LPC Bridge (rev a2)
00:01.1 SMBus: nVidia Corporation MCP78S [GeForce 8200] SMBus (rev a1)
00:01.2 RAM memory: nVidia Corporation MCP78S [GeForce 8200] Memory
Controller (rev a1)
00:01.3 Co-processor: nVidia Corporation MCP78S [GeForce 8200]
Co-Processor (rev a2)
00:01.4 RAM memory: nVidia Corporation MCP78S [GeForce 8200] Memory
Controller (rev a1)
00:02.0 USB Controller: nVidia Corporation MCP78S [GeForce 8200] OHCI
USB 1.1 Controller (rev a1)
00:02.1 USB Controller: nVidia Corporation MCP78S [GeForce 8200] EHCI
USB 2.0 Controller (rev a1)
00:04.0 USB Controller: nVidia Corporation MCP78S [GeForce 8200] OHCI
USB 1.1 Controller (rev a1)
00:04.1 USB Controller: nVidia Corporation MCP78S [GeForce 8200] EHCI
USB 2.0 Controller (rev a1)
00:06.0 IDE interface: nVidia Corporation MCP78S [GeForce 8200] IDE (rev a1)
00:07.0 Audio device: nVidia Corporation MCP78S [GeForce 8200] High
Definition Audio (rev a1)
00:08.0 PCI bridge: nVidia Corporation MCP78S [GeForce 8200] PCI Bridge (rev a1)
00:09.0 IDE interface: nVidia Corporation MCP78S [GeForce 8200] SATA
Controller (non-AHCI mode) (rev a2)
00:0b.0 PCI bridge: nVidia Corporation MCP78S [GeForce 8200] PCI
Express Bridge (rev a1)
00:10.0 PCI bridge: nVidia Corporation MCP78S [GeForce 8200] PCI
Express Bridge (rev a1)
00:12.0 PCI bridge: nVidia Corporation MCP78S [GeForce 8200] PCI
Express Bridge (rev a1)
00:13.0 PCI bridge: nVidia Corporation MCP78S [GeForce 8200] PCI Bridge (rev a1)
00:14.0 PCI bridge: nVidia Corporation MCP78S [GeForce 8200] PCI Bridge (rev a1)
00:18.0 Host bridge: Advanced Micro Devices [AMD] K8
[Athlon64/Opteron] HyperTransport Technology Configuration
00:18.1 Host bridge: Advanced Micro Devices [AMD] K8
[Athlon64/Opteron] Address Map
00:18.2 Host bridge: Advanced Micro Devices [AMD] K8
[Athlon64/Opteron] DRAM Controller
00:18.3 Host bridge: Advanced Micro Devices [AMD] K8
[Athlon64/Opteron] Miscellaneous Control
01:06.0 Ethernet controller: Atheros Communications Inc. Atheros
AR5001X+ Wireless Network Adapter (rev 01)
02:00.0 VGA compatible controller: nVidia Corporation GeForce 8100 /
nForce 720a (rev a2)
05:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd.
RTL8111/8168B PCI Express Gigabit Ethernet controller (rev 02)
----------

Thanks for your help,

Richard
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Next message: Miklos Szeredi: "[patch] don't preempt not TASK_RUNNING tasks"
Previous message: Lai Jiangshan: "Re: [PATCH] rcu_barrier VS cpu_hotplug: Ensure callbacks in deadcpu are migrated to online cpu"
Next in thread: Andrew Morton: "Re: Severe data corruption with ext4"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]