Crash...

Crash...

[Andrea Gelmini]

Hi all,
   thanks a lot for nilfs2.
   I'm trying to migrate my /home on nilfs2, but I've got this problem
doing rsync:

[ 4808.492544] ------------[ cut here ]------------
[ 4808.492547] kernel BUG at fs/nilfs2/segment.c:744!
[ 4808.492549] invalid opcode: 0000 [#1] SMP
[ 4808.492551] last sysfs file: /sys/devices/virtual/block/dm-0/range
[ 4808.492552] Modules linked in: nilfs2 reiserfs binfmt_misc rfcomm
bridge stp llc bnep sco l2cap bluetooth rfkill kqemu video backlight
output sbs sbshc pci_slot container battery ac loop snd_hda_codec_idt
snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss
snd_pcm snd_seq_dummy snd_seq_oss snd_seq_midi snd_rawmidi
snd_seq_midi_event snd_seq iTCO_wdt psmouse snd_timer snd_seq_device
iTCO_vendor_support pcspkr serio_raw processor rtc_cmos rtc_core
rtc_lib rt2860sta(C) snd joydev evdev button soundcore snd_page_alloc
xfs exportfs sha256_generic usbhid hid sg sr_mod usb_storage
usb_libusual sd_mod cdrom ata_generic pata_acpi pata_marvell ata_piix
ohci1394 ieee1394 uhci_hcd ehci_hcd libata scsi_mod e1000e usbcore
nls_base dm_snapshot thermal fan thermal_sys hwmon dm_mirror
dm_region_hash dm_log
[ 4808.492597]
[ 4808.492599] Pid: 15705, comm: segctord Tainted: G         C
(2.6.31-rc4g #6)
[ 4808.492601] EIP: 0060:[<f8439ffe>] EFLAGS: 00010246 CPU: 1
[ 4808.492611] EIP is at nilfs_segctor_scan_file+0xa5/0x19e [nilfs2]
[ 4808.492613] EAX: 40000020 EBX: 00000000 ECX: 0000000e EDX: c16b5cc0
[ 4808.492615] ESI: ef0b9500 EDI: dfe0f318 EBP: f4900dd0 ESP: f4900d5c
[ 4808.492616]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[ 4808.492618] Process segctord (pid: 15705, ti=f4900000 task=e2448dc0
task.ti=f4900000)
[ 4808.492620] Stack:
[ 4808.492621]  e52e42c0 f8449c98 e52e42c0 dfe0f2b8 dfe0f230 0000000e
00000000 c16b5cc0
[ 4808.492624] <0> c1580340 c14b9c20 c19dc5a0 c170f300 c1a4e4e0
c1996320 c18c9f80 c1950820
[ 4808.492628] <0> c1951de0 c18c9660 c19f9420 c1817ea0 c194fb80
f4900db0 f4900db0 d86ea228
[ 4808.492632] Call Trace:
[ 4808.492642]  [<f843abc8>] ? nilfs_segctor_do_construct+0x639/0x1dfe [nilfs2]
[ 4808.492652]  [<f843c511>] ? nilfs_segctor_construct+0x35/0xae [nilfs2]
[ 4808.492661]  [<f843ce6f>] ? nilfs_segctor_thread+0x138/0x2af [nilfs2]
[ 4808.492670]  [<f843cad5>] ? nilfs_construction_timeout+0x0/0xa [nilfs2]
[ 4808.492678]  [<f843cd37>] ? nilfs_segctor_thread+0x0/0x2af [nilfs2]
[ 4808.492683]  [<c1038145>] ? kthread+0x69/0x6e
[ 4808.492685]  [<c10380dc>] ? kthread+0x0/0x6e
[ 4808.492688]  [<c10033e7>] ? kernel_thread_helper+0x7/0x10
[ 4808.492690] Code: 8d 47 a0 89 55 9c 89 45 98 c7 45 f0 00 00 00 00
c7 45 a0 00 00 00 00 c7 45 a4 00 00 00 00 eb 5e 8b 54 9d a8 8b 02 f6
c4 08 75 04 <0f> 0b eb fe 8b 52 0c 89 55 94 89 d1 f6 01 02 74 21 8d 41
34 f0
[ 4808.492711] EIP: [<f8439ffe>] nilfs_segctor_scan_file+0xa5/0x19e
[nilfs2] SS:ESP 0068:f4900d5c
[ 4808.492721] ---[ end trace b07556da5ec25007 ]---

Well, I'm using Ubuntu 9.04 with a vanilla kernel 2.6.31-rc4 with
pulled "git://git.kernel.org/pub/scm/linux/kernel/git/ryusuke/nilfs2.git
experimental".
What other info can be useful to you? Instead of a giant attachment
with .config, /proc/cpu, lspci and so on, I can provide all of this
via web.

Thanks a lot for your work,
Andrea

Re: Crash...

[Ryusuke Konishi]

Hi,
On Thu, 23 Jul 2009 14:55:01 +0200, Andrea Gelmini wrote:
> Hi all,
>    thanks a lot for nilfs2.
>    I'm trying to migrate my /home on nilfs2, but I've got this problem
> doing rsync:
> 
> [ 4808.492544] ------------[ cut here ]------------
> [ 4808.492547] kernel BUG at fs/nilfs2/segment.c:744!
> [ 4808.492549] invalid opcode: 0000 [#1] SMP
> [ 4808.492551] last sysfs file: /sys/devices/virtual/block/dm-0/range
> [ 4808.492552] Modules linked in: nilfs2 reiserfs binfmt_misc rfcomm
> bridge stp llc bnep sco l2cap bluetooth rfkill kqemu video backlight
> output sbs sbshc pci_slot container battery ac loop snd_hda_codec_idt
> snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss
> snd_pcm snd_seq_dummy snd_seq_oss snd_seq_midi snd_rawmidi
> snd_seq_midi_event snd_seq iTCO_wdt psmouse snd_timer snd_seq_device
> iTCO_vendor_support pcspkr serio_raw processor rtc_cmos rtc_core
> rtc_lib rt2860sta(C) snd joydev evdev button soundcore snd_page_alloc
> xfs exportfs sha256_generic usbhid hid sg sr_mod usb_storage
> usb_libusual sd_mod cdrom ata_generic pata_acpi pata_marvell ata_piix
> ohci1394 ieee1394 uhci_hcd ehci_hcd libata scsi_mod e1000e usbcore
> nls_base dm_snapshot thermal fan thermal_sys hwmon dm_mirror
> dm_region_hash dm_log
> [ 4808.492597]
> [ 4808.492599] Pid: 15705, comm: segctord Tainted: G         C
> (2.6.31-rc4g #6)
> [ 4808.492601] EIP: 0060:[<f8439ffe>] EFLAGS: 00010246 CPU: 1
> [ 4808.492611] EIP is at nilfs_segctor_scan_file+0xa5/0x19e [nilfs2]
> [ 4808.492613] EAX: 40000020 EBX: 00000000 ECX: 0000000e EDX: c16b5cc0
> [ 4808.492615] ESI: ef0b9500 EDI: dfe0f318 EBP: f4900dd0 ESP: f4900d5c
> [ 4808.492616]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> [ 4808.492618] Process segctord (pid: 15705, ti=f4900000 task=e2448dc0
> task.ti=f4900000)
> [ 4808.492620] Stack:
> [ 4808.492621]  e52e42c0 f8449c98 e52e42c0 dfe0f2b8 dfe0f230 0000000e
> 00000000 c16b5cc0
> [ 4808.492624] <0> c1580340 c14b9c20 c19dc5a0 c170f300 c1a4e4e0
> c1996320 c18c9f80 c1950820
> [ 4808.492628] <0> c1951de0 c18c9660 c19f9420 c1817ea0 c194fb80
> f4900db0 f4900db0 d86ea228
> [ 4808.492632] Call Trace:
> [ 4808.492642]  [<f843abc8>] ? nilfs_segctor_do_construct+0x639/0x1dfe [nilfs2]
> [ 4808.492652]  [<f843c511>] ? nilfs_segctor_construct+0x35/0xae [nilfs2]
> [ 4808.492661]  [<f843ce6f>] ? nilfs_segctor_thread+0x138/0x2af [nilfs2]
> [ 4808.492670]  [<f843cad5>] ? nilfs_construction_timeout+0x0/0xa [nilfs2]
> [ 4808.492678]  [<f843cd37>] ? nilfs_segctor_thread+0x0/0x2af [nilfs2]
> [ 4808.492683]  [<c1038145>] ? kthread+0x69/0x6e
> [ 4808.492685]  [<c10380dc>] ? kthread+0x0/0x6e
> [ 4808.492688]  [<c10033e7>] ? kernel_thread_helper+0x7/0x10
> [ 4808.492690] Code: 8d 47 a0 89 55 9c 89 45 98 c7 45 f0 00 00 00 00
> c7 45 a0 00 00 00 00 c7 45 a4 00 00 00 00 eb 5e 8b 54 9d a8 8b 02 f6
> c4 08 75 04 <0f> 0b eb fe 8b 52 0c 89 55 94 89 d1 f6 01 02 74 21 8d 41
> 34 f0
> [ 4808.492711] EIP: [<f8439ffe>] nilfs_segctor_scan_file+0xa5/0x19e
> [nilfs2] SS:ESP 0068:f4900d5c
> [ 4808.492721] ---[ end trace b07556da5ec25007 ]---
> 
> Well, I'm using Ubuntu 9.04 with a vanilla kernel 2.6.31-rc4 with
> pulled "git://git.kernel.org/pub/scm/linux/kernel/git/ryusuke/nilfs2.git
> experimental".

Thank you for your report.

The log gives us really meaningful information.

First, I could identify the function which raised the assertion. 
( it's a page_buffers() call in nilfs_lookup_dirty_node_buffers() in
segment.c )

It also suggests that an inconsistent state in page cache of B-tree
nodes hit the function; the function found a dirty page, but the page
didn't have buffer heads which was supposed to be impossible for the
b-tree of nilfs.

I don't know yet why it can happen, but it's helpful to me in
narrowing down the cause.

> What other info can be useful to you? Instead of a giant attachment
> with .config, /proc/cpu, lspci and so on, I can provide all of this
> via web.
> 
> Thanks a lot for your work,
> Andrea

I will ask for your help if need arises.

Thanks,
Ryusuke Konishi

Re: Crash...

[Andrea Gelmini]

2009/7/23 Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org>:
> It also suggests that an inconsistent state in page cache of B-tree
> nodes hit the function; the function found a dirty page, but the page
> didn't have buffer heads which was supposed to be impossible for the
> b-tree of nilfs.

Well,
   thanks for your quick reply.
   Anyway, I can reproduce the same problem doing same things with
stable kernel (2.6.29.6) and nilfs2-module from git repository.
   I do this:
   -> mkfs.nilfs2 -b 1024 /dev/mapper/VG-NilfHome (maybe the problem
is the 1K block size?)
   -> mount /dev/mapper/VG-NilfHome /tmp/test/
   -> I run mirrordir (here's exactly as a "cp -a")

   It stucks at the same file as the crash before.
   It's a 5G file, if it could help.

  Here the log:
 1429.034107] ------------[ cut here ]------------
[ 1429.034111] kernel BUG at /home/gelma/dev/nilfs2-module/fs/segment.c:846!
[ 1429.034113] invalid opcode: 0000 [#1] SMP
[ 1429.034115] last sysfs file: /sys/devices/virtual/block/dm-1/range
[ 1429.034116] Modules linked in: nilfs2 binfmt_misc rfcomm bridge stp
llc bnep sco l2cap bluetooth kqemu video backlight output sbs sbshc
pci_slot container battery ac loop rtc_cmos psmouse nvidia(P) rtc_core
rt2860sta(C) rtc_lib serio_raw i2c_core pcspkr iTCO_wdt
iTCO_vendor_support evdev joydev button sha256_generic sr_mod cdrom sg
usbhid hid sd_mod ata_generic usb_storage libusual pata_acpi ohci1394
ieee1394 ata_piix ehci_hcd pata_marvell libata scsi_mod uhci_hcd
e1000e usbcore dm_snapshot thermal processor fan thermal_sys hwmon
dm_mirror dm_region_hash dm_log
[ 1429.034149]
[ 1429.034151] Pid: 10294, comm: segctord Tainted: P         C
(2.6.29.6 #1)
[ 1429.034153] EIP: 0060:[<f842fccc>] EFLAGS: 00010246 CPU: 1
[ 1429.034162] EIP is at nilfs_segctor_scan_file+0xa5/0x19e [nilfs2]
[ 1429.034164] EAX: 40000020 EBX: 00000000 ECX: 0000000e EDX: c149c880
[ 1429.034165] ESI: f1c1e900 EDI: eba22468 EBP: f15c6dec ESP: f15c6d78
[ 1429.034167]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[ 1429.034168] Process segctord (pid: 10294, ti=f15c6000 task=f2c07c90
task.ti=f15c6000)
[ 1429.034170] Stack:
[ 1429.034170]  e3918e80 f843faa8 e3918e80 eba22408 eba22380 0000000e
00000000 c149c880
[ 1429.034174]  c139cd20 c16c99c0 c112f9e0 c127dca0 c127e560 c127e580
c127dda0 c127ddc0
[ 1429.034178]  c127e5c0 c1599640 c1599660 c1599680 c15996a0 f15c6dcc
f15c6dcc e38fe628
[ 1429.034182] Call Trace:
[ 1429.034187]  [<f84308d6>] ? nilfs_segctor_do_construct+0x66a/0x1e7f [nilfs2]
[ 1429.034196]  [<c010edab>] ? smp_reschedule_interrupt+0x13/0x25
[ 1429.034200]  [<c0103414>] ? reschedule_interrupt+0x28/0x30
[ 1429.034203]  [<c01226e6>] ? finish_task_switch+0x2c/0xa9
[ 1429.034210]  [<f843227c>] ? nilfs_segctor_construct+0x35/0x7f [nilfs2]
[ 1429.034218]  [<f8432bab>] ? nilfs_segctor_thread+0x141/0x26d [nilfs2]
[ 1429.034226]  [<f8432831>] ? nilfs_construction_timeout+0x0/0xa [nilfs2]
[ 1429.034235]  [<f8432a6a>] ? nilfs_segctor_thread+0x0/0x26d [nilfs2]
[ 1429.034243]  [<c013564f>] ? kthread+0x3b/0x61
[ 1429.034245]  [<c0135614>] ? kthread+0x0/0x61
[ 1429.034247]  [<c0103623>] ? kernel_thread_helper+0x7/0x10
[ 1429.034250] Code: 8d 47 a0 89 55 9c 89 45 98 c7 45 f0 00 00 00 00
c7 45 a0 00 00 00 00 c7 45 a4 00 00 00 00 eb 5e 8b 54 9d a8 8b 02 f6
c4 08 75 04 <0f> 0b eb fe 8b 52 0c 89 55 94 89 d1 f6 01 02 74 21 8d 41
34 f0
[ 1429.034271] EIP: [<f842fccc>] nilfs_segctor_scan_file+0xa5/0x19e
[nilfs2] SS:ESP 0068:f15c6d78
[ 1429.034285] ---[ end trace 0ea06b01ef382693 ]---

Thanks a lot again,
Andrea

Re: Crash...

[Andrea Gelmini]

2009/7/23 Andrea Gelmini <andrea.gelmini@gmail.com>:
>   -> mkfs.nilfs2 -b 1024 /dev/mapper/VG-NilfHome (maybe the problem
> is the 1K block size?)

Ok, not defining '-b 1024' it works like a charm...

Thanks a lot,
Andrea
_______________________________________________
users mailing list
users@nilfs.org
https://www.nilfs.org/mailman/listinfo/users

Re: Crash...

[Jiro SEKIBA]

Hi,

I tried to reproduce the situation, but I can not reproduce the bug
with rc4, rc4+experimental on debian/lenny. 

At Thu, 23 Jul 2009 23:20:13 +0200,
Andrea Gelmini wrote:
> 
> 2009/7/23 Andrea Gelmini <andrea.gelmini-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>:
> >   -> mkfs.nilfs2 -b 1024 /dev/mapper/VG-NilfHome (maybe the problem
> > is the 1K block size?)
> 
> Ok, not defining '-b 1024' it works like a charm...

Looks like you are using lvm.  So differences are:
- debian or Ubuntsu 
- bare disk(/dev/sda?) or lvm.

Can you reproduce the bug without using lvm volume?

thanks,

regards,
-- 
Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>

Re: Crash...

[Andrea Gelmini]

2009/7/27 Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>:
> - debian or Ubuntsu
> - bare disk(/dev/sda?) or lvm.
>
> Can you reproduce the bug without using lvm volume?

Today I'll stress it with a normal primary partition.
Well, I'll do the test with stable kernel release to make it easier
for others to replicate the test.

Thanks a lot,
Andrea

Re: Crash...

[Jiro SEKIBA]

Hi, 

> I tried to reproduce the situation, but I can not reproduce the bug
> with rc4, rc4+experimental on debian/lenny. 

 Well, when I tried I got different kernel dump.
I don't know if it's related or not, but just in case.

 I got following with rc4 with device mapper, created nilfs2 filesystem on
it during rsync on the filesystem.


[405816.059174] general protection fault: 0000 [#1] SMP 
[405816.059205] last sysfs file: /sys/block/dm-0/removable
[405816.059233] CPU 0 
[405816.059255] Modules linked in: dm_mod nilfs2 ipv6 loop snd_hda_codec_realtek i2c_i801 i2c_core iTCO_wdt serio_raw snd_hda_intel snd_hda_codec pcspkr psmouse snd_pcm snd_timer snd button processor soundcore intel_agp snd_page_alloc evdev ext3 jbd mbcache raid10 raid456 raid6_pq async_xor async_memcpy async_tx xor raid1 raid0 multipath linear md_mod sg sr_mod sd_mod cdrom ahci libata scsi_mod tg3 libphy uhci_hcd ehci_hcd thermal fan thermal_sys
[405816.059462] Pid: 215, comm: kswapd0 Not tainted 2.6.31-rc4 #1 N8-S720XMZCUUA2
[405816.059504] RIP: 0010:[<ffffffff810a2ac0>]  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
[405816.059554] RSP: 0018:ffff88016cec1a40  EFLAGS: 00010282
[405816.059579] RAX: e7d50c6d4d1428d2 RBX: ffffea0003f5fbb0 RCX: 0000000000000800
[405816.059621] RDX: 0000000000000002 RSI: 0000000000000001 RDI: 0000000000000000
[405816.059663] RBP: ffffea0003f5fbd8 R08: 0000000000000001 R09: ffff88016fc075c0
[405816.059705] R10: 00003ffffffff000 R11: ffff88007a26f880 R12: ffff8801506f41a8
[405816.059747] R13: 0000000000000001 R14: 000000000000e800 R15: ffff88016cec1e10
[405816.059789] FS:  0000000000000000(0000) GS:ffff880028028000(0000) knlGS:0000000000000000
[405816.059833] CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
[405816.059858] CR2: 0000000001ae9618 CR3: 000000016c802000 CR4: 00000000000406f0
[405816.059900] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[405816.059943] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[405816.059985] Process kswapd0 (pid: 215, threadinfo ffff88016cec0000, task ffff88016f27f930)
[405816.060028] Stack:
[405816.060047]  0000000000000001 ffff88016cec1af0 0000000000000000 ffff88016cec1cb0
[405816.060078] <0> 0000000000000000 0000000000000017 0000000000000009 0000000000000001
[405816.060124] <0> ffffea00039702b8 ffffea0004aa0458 ffffea0004aa0810 ffffea0003970248
[405816.060185] Call Trace:
[405816.060208]  [<ffffffff8100c40e>] ? common_interrupt+0xe/0x13
[405816.060234]  [<ffffffff810a1cdb>] ? isolate_pages_global+0xa9/0x1f3
[405816.060262]  [<ffffffff810a338a>] ? shrink_list+0x2d8/0x5ec
[405816.060289]  [<ffffffff8110ac52>] ? proc_delete_inode+0x0/0x40
[405816.060317]  [<ffffffff8109f621>] ? determine_dirtyable_memory+0xd/0x1d
[405816.060345]  [<ffffffff8109f697>] ? get_dirty_limits+0x1d/0x256
[405816.060371]  [<ffffffff8100a54d>] ? __switch_to+0xae/0x266
[405816.060397]  [<ffffffff810a3921>] ? shrink_zone+0x283/0x335
[405816.060427]  [<ffffffffa0189217>] ? mb_cache_shrink_fn+0x26/0x117 [mbcache]
[405816.060456]  [<ffffffff810a3b14>] ? shrink_slab+0x141/0x153
[405816.060482]  [<ffffffff810a42ff>] ? kswapd+0x482/0x631
[405816.060507]  [<ffffffff810a1c32>] ? isolate_pages_global+0x0/0x1f3
[405816.060536]  [<ffffffff81053522>] ? autoremove_wake_function+0x0/0x2e
[405816.060564]  [<ffffffff810a3e7d>] ? kswapd+0x0/0x631
[405816.060588]  [<ffffffff810531d9>] ? kthread+0x84/0x8c
[405816.060614]  [<ffffffff8100caca>] ? child_rip+0xa/0x20
[405816.060639]  [<ffffffff81053155>] ? kthread+0x0/0x8c
[405816.060664]  [<ffffffff8100cac0>] ? child_rip+0x0/0x20
[405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
[405816.060819] RIP  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
[405816.060847]  RSP <ffff88016cec1a40>
[405816.061045] ---[ end trace c44a8d41c1aab2f3 ]---




-- 
Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>

Re: Crash...

[Ryusuke Konishi]

Hi,
On Wed, 29 Jul 2009 11:49:12 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> Hi, 
> 
> > I tried to reproduce the situation, but I can not reproduce the bug
> > with rc4, rc4+experimental on debian/lenny. 
> 
>  Well, when I tried I got different kernel dump.
> I don't know if it's related or not, but just in case.
> 
>  I got following with rc4 with device mapper, created nilfs2 filesystem on
> it during rsync on the filesystem.

shrink_page_list() is a core memory management function to reclaim
free pages.

Could you send me the disassembled source of mm/vmscan.o ?
You cat get it by using objdump command:

 $ cd linux/mm
 $ objdump -D vmscan.o > vmscan.s

The instruction in question is that has the code "<48>" in the
following sequence.

> [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 

Cheers,
Ryusuke Konishi 
 
> [405816.059174] general protection fault: 0000 [#1] SMP 
> [405816.059205] last sysfs file: /sys/block/dm-0/removable
> [405816.059233] CPU 0 
> [405816.059255] Modules linked in: dm_mod nilfs2 ipv6 loop snd_hda_codec_realtek i2c_i801 i2c_core iTCO_wdt serio_raw snd_hda_intel snd_hda_codec pcspkr psmouse snd_pcm snd_timer snd button processor soundcore intel_agp snd_page_alloc evdev ext3 jbd mbcache raid10 raid456 raid6_pq async_xor async_memcpy async_tx xor raid1 raid0 multipath linear md_mod sg sr_mod sd_mod cdrom ahci libata scsi_mod tg3 libphy uhci_hcd ehci_hcd thermal fan thermal_sys
> [405816.059462] Pid: 215, comm: kswapd0 Not tainted 2.6.31-rc4 #1 N8-S720XMZCUUA2
> [405816.059504] RIP: 0010:[<ffffffff810a2ac0>]  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> [405816.059554] RSP: 0018:ffff88016cec1a40  EFLAGS: 00010282
> [405816.059579] RAX: e7d50c6d4d1428d2 RBX: ffffea0003f5fbb0 RCX: 0000000000000800
> [405816.059621] RDX: 0000000000000002 RSI: 0000000000000001 RDI: 0000000000000000
> [405816.059663] RBP: ffffea0003f5fbd8 R08: 0000000000000001 R09: ffff88016fc075c0
> [405816.059705] R10: 00003ffffffff000 R11: ffff88007a26f880 R12: ffff8801506f41a8
> [405816.059747] R13: 0000000000000001 R14: 000000000000e800 R15: ffff88016cec1e10
> [405816.059789] FS:  0000000000000000(0000) GS:ffff880028028000(0000) knlGS:0000000000000000
> [405816.059833] CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> [405816.059858] CR2: 0000000001ae9618 CR3: 000000016c802000 CR4: 00000000000406f0
> [405816.059900] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [405816.059943] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> [405816.059985] Process kswapd0 (pid: 215, threadinfo ffff88016cec0000, task ffff88016f27f930)
> [405816.060028] Stack:
> [405816.060047]  0000000000000001 ffff88016cec1af0 0000000000000000 ffff88016cec1cb0
> [405816.060078] <0> 0000000000000000 0000000000000017 0000000000000009 0000000000000001
> [405816.060124] <0> ffffea00039702b8 ffffea0004aa0458 ffffea0004aa0810 ffffea0003970248
> [405816.060185] Call Trace:
> [405816.060208]  [<ffffffff8100c40e>] ? common_interrupt+0xe/0x13
> [405816.060234]  [<ffffffff810a1cdb>] ? isolate_pages_global+0xa9/0x1f3
> [405816.060262]  [<ffffffff810a338a>] ? shrink_list+0x2d8/0x5ec
> [405816.060289]  [<ffffffff8110ac52>] ? proc_delete_inode+0x0/0x40
> [405816.060317]  [<ffffffff8109f621>] ? determine_dirtyable_memory+0xd/0x1d
> [405816.060345]  [<ffffffff8109f697>] ? get_dirty_limits+0x1d/0x256
> [405816.060371]  [<ffffffff8100a54d>] ? __switch_to+0xae/0x266
> [405816.060397]  [<ffffffff810a3921>] ? shrink_zone+0x283/0x335
> [405816.060427]  [<ffffffffa0189217>] ? mb_cache_shrink_fn+0x26/0x117 [mbcache]
> [405816.060456]  [<ffffffff810a3b14>] ? shrink_slab+0x141/0x153
> [405816.060482]  [<ffffffff810a42ff>] ? kswapd+0x482/0x631
> [405816.060507]  [<ffffffff810a1c32>] ? isolate_pages_global+0x0/0x1f3
> [405816.060536]  [<ffffffff81053522>] ? autoremove_wake_function+0x0/0x2e
> [405816.060564]  [<ffffffff810a3e7d>] ? kswapd+0x0/0x631
> [405816.060588]  [<ffffffff810531d9>] ? kthread+0x84/0x8c
> [405816.060614]  [<ffffffff8100caca>] ? child_rip+0xa/0x20
> [405816.060639]  [<ffffffff81053155>] ? kthread+0x0/0x8c
> [405816.060664]  [<ffffffff8100cac0>] ? child_rip+0x0/0x20
> [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> [405816.060819] RIP  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> [405816.060847]  RSP <ffff88016cec1a40>
> [405816.061045] ---[ end trace c44a8d41c1aab2f3 ]---
> 
> 
> 
> 
> -- 
> Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>
> _______________________________________________
> users mailing list
> users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> https://www.nilfs.org/mailman/listinfo/users

Re: Crash...

[Jiro SEKIBA]

Hi,

At Wed, 29 Jul 2009 12:46:38 +0900 (JST),
Ryusuke Konishi wrote:
> 
> Hi,
> On Wed, 29 Jul 2009 11:49:12 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> > Hi, 
> > 
> > > I tried to reproduce the situation, but I can not reproduce the bug
> > > with rc4, rc4+experimental on debian/lenny. 
> > 
> >  Well, when I tried I got different kernel dump.
> > I don't know if it's related or not, but just in case.
> > 
> >  I got following with rc4 with device mapper, created nilfs2 filesystem on
> > it during rsync on the filesystem.
> 
> shrink_page_list() is a core memory management function to reclaim
> free pages.
> 
> Could you send me the disassembled source of mm/vmscan.o ?
> You cat get it by using objdump command:

Here is the corresponded dump of shrink_page_list:

     ee4:       85 c0                   test   %eax,%eax
     ee6:       0f 84 d1 02 00 00       je     11bd <shrink_page_list+0x559>
     eec:       f0 80 65 d8 ef          lock andb $0xef,-0x28(%rbp)
     ef1:       48 c7 c6 00 00 00 00    mov    $0x0,%rsi
     ef8:       48 c7 c7 00 00 00 00    mov    $0x0,%rdi
     eff:       31 c0                   xor    %eax,%eax
     f01:       e8 00 00 00 00          callq  f06 <shrink_page_list+0x2a2>
     f06:       e9 b6 01 00 00          jmpq   10c1 <shrink_page_list+0x45d>
     f0b:       49 8b 44 24 58          mov    0x58(%r12),%rax
     f10:       48 83 38 00             cmpq   $0x0,(%rax)
     f14:       0f 84 79 02 00 00       je     1193 <shrink_page_list+0x52f>
     f1a:       65 48 8b 04 25 00 00    mov    %gs:0x0,%rax
     f21:       00 00 
     f23:       f6 40 16 80             testb  $0x80,0x16(%rax)

looks like <48> is cmpq at f10.

>  $ cd linux/mm
>  $ objdump -D vmscan.o > vmscan.s
> 
> The instruction in question is that has the code "<48>" in the
> following sequence.
> 
> > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> 
> Cheers,
> Ryusuke Konishi 
>  
> > [405816.059174] general protection fault: 0000 [#1] SMP 
> > [405816.059205] last sysfs file: /sys/block/dm-0/removable
> > [405816.059233] CPU 0 
> > [405816.059255] Modules linked in: dm_mod nilfs2 ipv6 loop snd_hda_codec_realtek i2c_i801 i2c_core iTCO_wdt serio_raw snd_hda_intel snd_hda_codec pcspkr psmouse snd_pcm snd_timer snd button processor soundcore intel_agp snd_page_alloc evdev ext3 jbd mbcache raid10 raid456 raid6_pq async_xor async_memcpy async_tx xor raid1 raid0 multipath linear md_mod sg sr_mod sd_mod cdrom ahci libata scsi_mod tg3 libphy uhci_hcd ehci_hcd thermal fan thermal_sys
> > [405816.059462] Pid: 215, comm: kswapd0 Not tainted 2.6.31-rc4 #1 N8-S720XMZCUUA2
> > [405816.059504] RIP: 0010:[<ffffffff810a2ac0>]  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > [405816.059554] RSP: 0018:ffff88016cec1a40  EFLAGS: 00010282
> > [405816.059579] RAX: e7d50c6d4d1428d2 RBX: ffffea0003f5fbb0 RCX: 0000000000000800
> > [405816.059621] RDX: 0000000000000002 RSI: 0000000000000001 RDI: 0000000000000000
> > [405816.059663] RBP: ffffea0003f5fbd8 R08: 0000000000000001 R09: ffff88016fc075c0
> > [405816.059705] R10: 00003ffffffff000 R11: ffff88007a26f880 R12: ffff8801506f41a8
> > [405816.059747] R13: 0000000000000001 R14: 000000000000e800 R15: ffff88016cec1e10
> > [405816.059789] FS:  0000000000000000(0000) GS:ffff880028028000(0000) knlGS:0000000000000000
> > [405816.059833] CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> > [405816.059858] CR2: 0000000001ae9618 CR3: 000000016c802000 CR4: 00000000000406f0
> > [405816.059900] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > [405816.059943] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > [405816.059985] Process kswapd0 (pid: 215, threadinfo ffff88016cec0000, task ffff88016f27f930)
> > [405816.060028] Stack:
> > [405816.060047]  0000000000000001 ffff88016cec1af0 0000000000000000 ffff88016cec1cb0
> > [405816.060078] <0> 0000000000000000 0000000000000017 0000000000000009 0000000000000001
> > [405816.060124] <0> ffffea00039702b8 ffffea0004aa0458 ffffea0004aa0810 ffffea0003970248
> > [405816.060185] Call Trace:
> > [405816.060208]  [<ffffffff8100c40e>] ? common_interrupt+0xe/0x13
> > [405816.060234]  [<ffffffff810a1cdb>] ? isolate_pages_global+0xa9/0x1f3
> > [405816.060262]  [<ffffffff810a338a>] ? shrink_list+0x2d8/0x5ec
> > [405816.060289]  [<ffffffff8110ac52>] ? proc_delete_inode+0x0/0x40
> > [405816.060317]  [<ffffffff8109f621>] ? determine_dirtyable_memory+0xd/0x1d
> > [405816.060345]  [<ffffffff8109f697>] ? get_dirty_limits+0x1d/0x256
> > [405816.060371]  [<ffffffff8100a54d>] ? __switch_to+0xae/0x266
> > [405816.060397]  [<ffffffff810a3921>] ? shrink_zone+0x283/0x335
> > [405816.060427]  [<ffffffffa0189217>] ? mb_cache_shrink_fn+0x26/0x117 [mbcache]
> > [405816.060456]  [<ffffffff810a3b14>] ? shrink_slab+0x141/0x153
> > [405816.060482]  [<ffffffff810a42ff>] ? kswapd+0x482/0x631
> > [405816.060507]  [<ffffffff810a1c32>] ? isolate_pages_global+0x0/0x1f3
> > [405816.060536]  [<ffffffff81053522>] ? autoremove_wake_function+0x0/0x2e
> > [405816.060564]  [<ffffffff810a3e7d>] ? kswapd+0x0/0x631
> > [405816.060588]  [<ffffffff810531d9>] ? kthread+0x84/0x8c
> > [405816.060614]  [<ffffffff8100caca>] ? child_rip+0xa/0x20
> > [405816.060639]  [<ffffffff81053155>] ? kthread+0x0/0x8c
> > [405816.060664]  [<ffffffff8100cac0>] ? child_rip+0x0/0x20
> > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> > [405816.060819] RIP  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > [405816.060847]  RSP <ffff88016cec1a40>
> > [405816.061045] ---[ end trace c44a8d41c1aab2f3 ]---
> > 
> > 
> > 
> > 
> > -- 
> > Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>
> > _______________________________________________
> > users mailing list
> > users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> > https://www.nilfs.org/mailman/listinfo/users
> _______________________________________________
> users mailing list
> users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> https://www.nilfs.org/mailman/listinfo/users
> 
> 
> 


-- 
Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>

Re: Crash...

[Ryusuke Konishi]

On Wed, 29 Jul 2009 13:40:56 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> Hi,
> 
> At Wed, 29 Jul 2009 12:46:38 +0900 (JST),
> Ryusuke Konishi wrote:
> > 
> > Hi,
> > On Wed, 29 Jul 2009 11:49:12 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> > > Hi, 
> > > 
> > > > I tried to reproduce the situation, but I can not reproduce the bug
> > > > with rc4, rc4+experimental on debian/lenny. 
> > > 
> > >  Well, when I tried I got different kernel dump.
> > > I don't know if it's related or not, but just in case.
> > > 
> > >  I got following with rc4 with device mapper, created nilfs2 filesystem on
> > > it during rsync on the filesystem.
> > 
> > shrink_page_list() is a core memory management function to reclaim
> > free pages.
> > 
> > Could you send me the disassembled source of mm/vmscan.o ?
> > You cat get it by using objdump command:
> 
> Here is the corresponded dump of shrink_page_list:
> 
>      ee4:       85 c0                   test   %eax,%eax
>      ee6:       0f 84 d1 02 00 00       je     11bd <shrink_page_list+0x559>
>      eec:       f0 80 65 d8 ef          lock andb $0xef,-0x28(%rbp)
>      ef1:       48 c7 c6 00 00 00 00    mov    $0x0,%rsi
>      ef8:       48 c7 c7 00 00 00 00    mov    $0x0,%rdi
>      eff:       31 c0                   xor    %eax,%eax
>      f01:       e8 00 00 00 00          callq  f06 <shrink_page_list+0x2a2>
>      f06:       e9 b6 01 00 00          jmpq   10c1 <shrink_page_list+0x45d>
>      f0b:       49 8b 44 24 58          mov    0x58(%r12),%rax
>      f10:       48 83 38 00             cmpq   $0x0,(%rax)
>      f14:       0f 84 79 02 00 00       je     1193 <shrink_page_list+0x52f>
>      f1a:       65 48 8b 04 25 00 00    mov    %gs:0x0,%rax
>      f21:       00 00 
>      f23:       f6 40 16 80             testb  $0x80,0x16(%rax)
> 
> looks like <48> is cmpq at f10.

Thanks.

It looks like a part of the pageout() function inlined in the
shrink_page_list().

static pageout_t pageout(struct page *page, struct address_space *mapping,
                                                enum pageout_io sync_writeback)
{
	...
        if (!is_page_cache_freeable(page))
                return PAGE_KEEP;
        if (!mapping) {
                /*
                 * Some data journaling orphaned pages can have
                 * page->mapping == NULL while being dirty with clean buffers.
                 */
                if (page_has_private(page)) {
                        if (try_to_free_buffers(page)) {
                                ClearPageDirty(page);
                                printk("%s: orphaned page\n", __func__);
                                return PAGE_CLEAN;
                        }
                }
                return PAGE_KEEP;
        }
        if (mapping->a_ops->writepage == NULL)
                return PAGE_ACTIVATE;
       ...

The above ``a_ops->writepage'' causes the violative access.  According
to your log, mapping->a_ops (= RAX) seems to store a meaningless value.

Maybe the mapping->a_ops is not set on the page.

Ok, I'll check if nilfs can cause this sort of problem.

Thanks,
Ryusuke Konishi

> >  $ cd linux/mm
> >  $ objdump -D vmscan.o > vmscan.s
> > 
> > The instruction in question is that has the code "<48>" in the
> > following sequence.
> > 
> > > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> > 
> > Cheers,
> > Ryusuke Konishi 
> >  
> > > [405816.059174] general protection fault: 0000 [#1] SMP 
> > > [405816.059205] last sysfs file: /sys/block/dm-0/removable
> > > [405816.059233] CPU 0 
> > > [405816.059255] Modules linked in: dm_mod nilfs2 ipv6 loop snd_hda_codec_realtek i2c_i801 i2c_core iTCO_wdt serio_raw snd_hda_intel snd_hda_codec pcspkr psmouse snd_pcm snd_timer snd button processor soundcore intel_agp snd_page_alloc evdev ext3 jbd mbcache raid10 raid456 raid6_pq async_xor async_memcpy async_tx xor raid1 raid0 multipath linear md_mod sg sr_mod sd_mod cdrom ahci libata scsi_mod tg3 libphy uhci_hcd ehci_hcd thermal fan thermal_sys
> > > [405816.059462] Pid: 215, comm: kswapd0 Not tainted 2.6.31-rc4 #1 N8-S720XMZCUUA2
> > > [405816.059504] RIP: 0010:[<ffffffff810a2ac0>]  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > > [405816.059554] RSP: 0018:ffff88016cec1a40  EFLAGS: 00010282
> > > [405816.059579] RAX: e7d50c6d4d1428d2 RBX: ffffea0003f5fbb0 RCX: 0000000000000800
> > > [405816.059621] RDX: 0000000000000002 RSI: 0000000000000001 RDI: 0000000000000000
> > > [405816.059663] RBP: ffffea0003f5fbd8 R08: 0000000000000001 R09: ffff88016fc075c0
> > > [405816.059705] R10: 00003ffffffff000 R11: ffff88007a26f880 R12: ffff8801506f41a8
> > > [405816.059747] R13: 0000000000000001 R14: 000000000000e800 R15: ffff88016cec1e10
> > > [405816.059789] FS:  0000000000000000(0000) GS:ffff880028028000(0000) knlGS:0000000000000000
> > > [405816.059833] CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> > > [405816.059858] CR2: 0000000001ae9618 CR3: 000000016c802000 CR4: 00000000000406f0
> > > [405816.059900] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > > [405816.059943] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > > [405816.059985] Process kswapd0 (pid: 215, threadinfo ffff88016cec0000, task ffff88016f27f930)
> > > [405816.060028] Stack:
> > > [405816.060047]  0000000000000001 ffff88016cec1af0 0000000000000000 ffff88016cec1cb0
> > > [405816.060078] <0> 0000000000000000 0000000000000017 0000000000000009 0000000000000001
> > > [405816.060124] <0> ffffea00039702b8 ffffea0004aa0458 ffffea0004aa0810 ffffea0003970248
> > > [405816.060185] Call Trace:
> > > [405816.060208]  [<ffffffff8100c40e>] ? common_interrupt+0xe/0x13
> > > [405816.060234]  [<ffffffff810a1cdb>] ? isolate_pages_global+0xa9/0x1f3
> > > [405816.060262]  [<ffffffff810a338a>] ? shrink_list+0x2d8/0x5ec
> > > [405816.060289]  [<ffffffff8110ac52>] ? proc_delete_inode+0x0/0x40
> > > [405816.060317]  [<ffffffff8109f621>] ? determine_dirtyable_memory+0xd/0x1d
> > > [405816.060345]  [<ffffffff8109f697>] ? get_dirty_limits+0x1d/0x256
> > > [405816.060371]  [<ffffffff8100a54d>] ? __switch_to+0xae/0x266
> > > [405816.060397]  [<ffffffff810a3921>] ? shrink_zone+0x283/0x335
> > > [405816.060427]  [<ffffffffa0189217>] ? mb_cache_shrink_fn+0x26/0x117 [mbcache]
> > > [405816.060456]  [<ffffffff810a3b14>] ? shrink_slab+0x141/0x153
> > > [405816.060482]  [<ffffffff810a42ff>] ? kswapd+0x482/0x631
> > > [405816.060507]  [<ffffffff810a1c32>] ? isolate_pages_global+0x0/0x1f3
> > > [405816.060536]  [<ffffffff81053522>] ? autoremove_wake_function+0x0/0x2e
> > > [405816.060564]  [<ffffffff810a3e7d>] ? kswapd+0x0/0x631
> > > [405816.060588]  [<ffffffff810531d9>] ? kthread+0x84/0x8c
> > > [405816.060614]  [<ffffffff8100caca>] ? child_rip+0xa/0x20
> > > [405816.060639]  [<ffffffff81053155>] ? kthread+0x0/0x8c
> > > [405816.060664]  [<ffffffff8100cac0>] ? child_rip+0x0/0x20
> > > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> > > [405816.060819] RIP  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > > [405816.060847]  RSP <ffff88016cec1a40>
> > > [405816.061045] ---[ end trace c44a8d41c1aab2f3 ]---
> > > 
> > > 
> > > 
> > > 
> > > -- 
> > > Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>
> > > _______________________________________________
> > > users mailing list
> > > users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> > > https://www.nilfs.org/mailman/listinfo/users
> > _______________________________________________
> > users mailing list
> > users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> > https://www.nilfs.org/mailman/listinfo/users
> > 
> > 
> > 
> 
> 
> -- 
> Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>
> _______________________________________________
> users mailing list
> users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> https://www.nilfs.org/mailman/listinfo/users

kernel oops on shrink_page_list (was Re: Crash...)

[Ryusuke Konishi]

Hi,

Recently, I saw this oops rather frequently for the latest
nilfs2-module.git, which applied a bunch of patches backported from
2.6.31-rc.

So, I'm doing git bisect to find out the cause for the changes since
nilfs-2.0.15.  So far, nilfs-2.0.15 seems stable to me.

If you see this oops on the nilfs-2.0.15 or prior versions (or at
kernel-2.6.30), please let me know.


Thanks,
Ryusuke Konishi

On Wed, 29 Jul 2009 14:08:21 +0900 (JST), Ryusuke Konishi wrote:
> On Wed, 29 Jul 2009 13:40:56 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> > Hi,
> > 
> > At Wed, 29 Jul 2009 12:46:38 +0900 (JST),
> > Ryusuke Konishi wrote:
> > > 
> > > Hi,
> > > On Wed, 29 Jul 2009 11:49:12 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> > > > Hi, 
> > > > 
> > > > > I tried to reproduce the situation, but I can not reproduce the bug
> > > > > with rc4, rc4+experimental on debian/lenny. 
> > > > 
> > > >  Well, when I tried I got different kernel dump.
> > > > I don't know if it's related or not, but just in case.
> > > > 
> > > >  I got following with rc4 with device mapper, created nilfs2 filesystem on
> > > > it during rsync on the filesystem.
> > > 
> > > shrink_page_list() is a core memory management function to reclaim
> > > free pages.
> > > 
> > > Could you send me the disassembled source of mm/vmscan.o ?
> > > You cat get it by using objdump command:
> > 
> > Here is the corresponded dump of shrink_page_list:
> > 
> >      ee4:       85 c0                   test   %eax,%eax
> >      ee6:       0f 84 d1 02 00 00       je     11bd <shrink_page_list+0x559>
> >      eec:       f0 80 65 d8 ef          lock andb $0xef,-0x28(%rbp)
> >      ef1:       48 c7 c6 00 00 00 00    mov    $0x0,%rsi
> >      ef8:       48 c7 c7 00 00 00 00    mov    $0x0,%rdi
> >      eff:       31 c0                   xor    %eax,%eax
> >      f01:       e8 00 00 00 00          callq  f06 <shrink_page_list+0x2a2>
> >      f06:       e9 b6 01 00 00          jmpq   10c1 <shrink_page_list+0x45d>
> >      f0b:       49 8b 44 24 58          mov    0x58(%r12),%rax
> >      f10:       48 83 38 00             cmpq   $0x0,(%rax)
> >      f14:       0f 84 79 02 00 00       je     1193 <shrink_page_list+0x52f>
> >      f1a:       65 48 8b 04 25 00 00    mov    %gs:0x0,%rax
> >      f21:       00 00 
> >      f23:       f6 40 16 80             testb  $0x80,0x16(%rax)
> > 
> > looks like <48> is cmpq at f10.
> 
> Thanks.
> 
> It looks like a part of the pageout() function inlined in the
> shrink_page_list().
> 
> static pageout_t pageout(struct page *page, struct address_space *mapping,
>                                                 enum pageout_io sync_writeback)
> {
> 	...
>         if (!is_page_cache_freeable(page))
>                 return PAGE_KEEP;
>         if (!mapping) {
>                 /*
>                  * Some data journaling orphaned pages can have
>                  * page->mapping == NULL while being dirty with clean buffers.
>                  */
>                 if (page_has_private(page)) {
>                         if (try_to_free_buffers(page)) {
>                                 ClearPageDirty(page);
>                                 printk("%s: orphaned page\n", __func__);
>                                 return PAGE_CLEAN;
>                         }
>                 }
>                 return PAGE_KEEP;
>         }
>         if (mapping->a_ops->writepage == NULL)
>                 return PAGE_ACTIVATE;
>        ...
> 
> The above ``a_ops->writepage'' causes the violative access.  According
> to your log, mapping->a_ops (= RAX) seems to store a meaningless value.
> 
> Maybe the mapping->a_ops is not set on the page.
> 
> Ok, I'll check if nilfs can cause this sort of problem.
> 
> Thanks,
> Ryusuke Konishi
> 
> > >  $ cd linux/mm
> > >  $ objdump -D vmscan.o > vmscan.s
> > > 
> > > The instruction in question is that has the code "<48>" in the
> > > following sequence.
> > > 
> > > > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> > > 
> > > Cheers,
> > > Ryusuke Konishi 
> > >  
> > > > [405816.059174] general protection fault: 0000 [#1] SMP 
> > > > [405816.059205] last sysfs file: /sys/block/dm-0/removable
> > > > [405816.059233] CPU 0 
> > > > [405816.059255] Modules linked in: dm_mod nilfs2 ipv6 loop snd_hda_codec_realtek i2c_i801 i2c_core iTCO_wdt serio_raw snd_hda_intel snd_hda_codec pcspkr psmouse snd_pcm snd_timer snd button processor soundcore intel_agp snd_page_alloc evdev ext3 jbd mbcache raid10 raid456 raid6_pq async_xor async_memcpy async_tx xor raid1 raid0 multipath linear md_mod sg sr_mod sd_mod cdrom ahci libata scsi_mod tg3 libphy uhci_hcd ehci_hcd thermal fan thermal_sys
> > > > [405816.059462] Pid: 215, comm: kswapd0 Not tainted 2.6.31-rc4 #1 N8-S720XMZCUUA2
> > > > [405816.059504] RIP: 0010:[<ffffffff810a2ac0>]  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > > > [405816.059554] RSP: 0018:ffff88016cec1a40  EFLAGS: 00010282
> > > > [405816.059579] RAX: e7d50c6d4d1428d2 RBX: ffffea0003f5fbb0 RCX: 0000000000000800
> > > > [405816.059621] RDX: 0000000000000002 RSI: 0000000000000001 RDI: 0000000000000000
> > > > [405816.059663] RBP: ffffea0003f5fbd8 R08: 0000000000000001 R09: ffff88016fc075c0
> > > > [405816.059705] R10: 00003ffffffff000 R11: ffff88007a26f880 R12: ffff8801506f41a8
> > > > [405816.059747] R13: 0000000000000001 R14: 000000000000e800 R15: ffff88016cec1e10
> > > > [405816.059789] FS:  0000000000000000(0000) GS:ffff880028028000(0000) knlGS:0000000000000000
> > > > [405816.059833] CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> > > > [405816.059858] CR2: 0000000001ae9618 CR3: 000000016c802000 CR4: 00000000000406f0
> > > > [405816.059900] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > > > [405816.059943] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > > > [405816.059985] Process kswapd0 (pid: 215, threadinfo ffff88016cec0000, task ffff88016f27f930)
> > > > [405816.060028] Stack:
> > > > [405816.060047]  0000000000000001 ffff88016cec1af0 0000000000000000 ffff88016cec1cb0
> > > > [405816.060078] <0> 0000000000000000 0000000000000017 0000000000000009 0000000000000001
> > > > [405816.060124] <0> ffffea00039702b8 ffffea0004aa0458 ffffea0004aa0810 ffffea0003970248
> > > > [405816.060185] Call Trace:
> > > > [405816.060208]  [<ffffffff8100c40e>] ? common_interrupt+0xe/0x13
> > > > [405816.060234]  [<ffffffff810a1cdb>] ? isolate_pages_global+0xa9/0x1f3
> > > > [405816.060262]  [<ffffffff810a338a>] ? shrink_list+0x2d8/0x5ec
> > > > [405816.060289]  [<ffffffff8110ac52>] ? proc_delete_inode+0x0/0x40
> > > > [405816.060317]  [<ffffffff8109f621>] ? determine_dirtyable_memory+0xd/0x1d
> > > > [405816.060345]  [<ffffffff8109f697>] ? get_dirty_limits+0x1d/0x256
> > > > [405816.060371]  [<ffffffff8100a54d>] ? __switch_to+0xae/0x266
> > > > [405816.060397]  [<ffffffff810a3921>] ? shrink_zone+0x283/0x335
> > > > [405816.060427]  [<ffffffffa0189217>] ? mb_cache_shrink_fn+0x26/0x117 [mbcache]
> > > > [405816.060456]  [<ffffffff810a3b14>] ? shrink_slab+0x141/0x153
> > > > [405816.060482]  [<ffffffff810a42ff>] ? kswapd+0x482/0x631
> > > > [405816.060507]  [<ffffffff810a1c32>] ? isolate_pages_global+0x0/0x1f3
> > > > [405816.060536]  [<ffffffff81053522>] ? autoremove_wake_function+0x0/0x2e
> > > > [405816.060564]  [<ffffffff810a3e7d>] ? kswapd+0x0/0x631
> > > > [405816.060588]  [<ffffffff810531d9>] ? kthread+0x84/0x8c
> > > > [405816.060614]  [<ffffffff8100caca>] ? child_rip+0xa/0x20
> > > > [405816.060639]  [<ffffffff81053155>] ? kthread+0x0/0x8c
> > > > [405816.060664]  [<ffffffff8100cac0>] ? child_rip+0x0/0x20
> > > > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> > > > [405816.060819] RIP  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > > > [405816.060847]  RSP <ffff88016cec1a40>
> > > > [405816.061045] ---[ end trace c44a8d41c1aab2f3 ]---
> > > > 
> > > > 
> > > > 
> > > > 
> > > > -- 
> > > > Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>
> > > > _______________________________________________
> > > > users mailing list
> > > > users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> > > > https://www.nilfs.org/mailman/listinfo/users
> > > _______________________________________________
> > > users mailing list
> > > users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> > > https://www.nilfs.org/mailman/listinfo/users
> > > 
> > > 
> > > 
> > 
> > 
> > -- 
> > Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>
> > _______________________________________________
> > users mailing list
> > users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
> > https://www.nilfs.org/mailman/listinfo/users

Re: kernel oops on shrink_page_list

[Ryusuke Konishi]

Hi everyone,

On Mon, 10 Aug 2009 15:54:20 +0900 (JST), Ryusuke Konishi wrote:
> Hi,
> 
> Recently, I saw this oops rather frequently for the latest
> nilfs2-module.git, which applied a bunch of patches backported from
> 2.6.31-rc.
> 
> So, I'm doing git bisect to find out the cause for the changes since
> nilfs-2.0.15.  So far, nilfs-2.0.15 seems stable to me.
> 
> If you see this oops on the nilfs-2.0.15 or prior versions (or at
> kernel-2.6.30), please let me know.
> 
> 
> Thanks,
> Ryusuke Konishi

After applying a nilfs patch merged in 2.6.31-rc6, this oops problem
totally disappeared.  So, I deem it fixed with the patch.

The patch got included in the stable kernel 2.6.30.5, and I've pushed
it to nilfs2-module.git, too.

I would recommend users having the same problem try upgrade to these
updated kernels.

Thanks,
Ryusuke Konishi


> On Wed, 29 Jul 2009 14:08:21 +0900 (JST), Ryusuke Konishi wrote:
> > On Wed, 29 Jul 2009 13:40:56 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> > > Hi,
> > > 
> > > At Wed, 29 Jul 2009 12:46:38 +0900 (JST),
> > > Ryusuke Konishi wrote:
> > > > 
> > > > Hi,
> > > > On Wed, 29 Jul 2009 11:49:12 +0900, Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org> wrote:
> > > > > Hi, 
> > > > > 
> > > > > > I tried to reproduce the situation, but I can not reproduce the bug
> > > > > > with rc4, rc4+experimental on debian/lenny. 
> > > > > 
> > > > >  Well, when I tried I got different kernel dump.
> > > > > I don't know if it's related or not, but just in case.
> > > > > 
> > > > >  I got following with rc4 with device mapper, created nilfs2 filesystem on
> > > > > it during rsync on the filesystem.
> > > > 
> > > > shrink_page_list() is a core memory management function to reclaim
> > > > free pages.
> > > > 
> > > > Could you send me the disassembled source of mm/vmscan.o ?
> > > > You cat get it by using objdump command:
> > > 
> > > Here is the corresponded dump of shrink_page_list:
> > > 
> > >      ee4:       85 c0                   test   %eax,%eax
> > >      ee6:       0f 84 d1 02 00 00       je     11bd <shrink_page_list+0x559>
> > >      eec:       f0 80 65 d8 ef          lock andb $0xef,-0x28(%rbp)
> > >      ef1:       48 c7 c6 00 00 00 00    mov    $0x0,%rsi
> > >      ef8:       48 c7 c7 00 00 00 00    mov    $0x0,%rdi
> > >      eff:       31 c0                   xor    %eax,%eax
> > >      f01:       e8 00 00 00 00          callq  f06 <shrink_page_list+0x2a2>
> > >      f06:       e9 b6 01 00 00          jmpq   10c1 <shrink_page_list+0x45d>
> > >      f0b:       49 8b 44 24 58          mov    0x58(%r12),%rax
> > >      f10:       48 83 38 00             cmpq   $0x0,(%rax)
> > >      f14:       0f 84 79 02 00 00       je     1193 <shrink_page_list+0x52f>
> > >      f1a:       65 48 8b 04 25 00 00    mov    %gs:0x0,%rax
> > >      f21:       00 00 
> > >      f23:       f6 40 16 80             testb  $0x80,0x16(%rax)
> > > 
> > > looks like <48> is cmpq at f10.
> > 
> > Thanks.
> > 
> > It looks like a part of the pageout() function inlined in the
> > shrink_page_list().
> > 
> > static pageout_t pageout(struct page *page, struct address_space *mapping,
> >                                                 enum pageout_io sync_writeback)
> > {
> > 	...
> >         if (!is_page_cache_freeable(page))
> >                 return PAGE_KEEP;
> >         if (!mapping) {
> >                 /*
> >                  * Some data journaling orphaned pages can have
> >                  * page->mapping == NULL while being dirty with clean buffers.
> >                  */
> >                 if (page_has_private(page)) {
> >                         if (try_to_free_buffers(page)) {
> >                                 ClearPageDirty(page);
> >                                 printk("%s: orphaned page\n", __func__);
> >                                 return PAGE_CLEAN;
> >                         }
> >                 }
> >                 return PAGE_KEEP;
> >         }
> >         if (mapping->a_ops->writepage == NULL)
> >                 return PAGE_ACTIVATE;
> >        ...
> > 
> > The above ``a_ops->writepage'' causes the violative access.  According
> > to your log, mapping->a_ops (= RAX) seems to store a meaningless value.
> > 
> > Maybe the mapping->a_ops is not set on the page.
> > 
> > Ok, I'll check if nilfs can cause this sort of problem.
> > 
> > Thanks,
> > Ryusuke Konishi
> > 
> > > >  $ cd linux/mm
> > > >  $ objdump -D vmscan.o > vmscan.s
> > > > 
> > > > The instruction in question is that has the code "<48>" in the
> > > > following sequence.
> > > > 
> > > > > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> > > > 
> > > > Cheers,
> > > > Ryusuke Konishi 
> > > >  
> > > > > [405816.059174] general protection fault: 0000 [#1] SMP 
> > > > > [405816.059205] last sysfs file: /sys/block/dm-0/removable
> > > > > [405816.059233] CPU 0 
> > > > > [405816.059255] Modules linked in: dm_mod nilfs2 ipv6 loop snd_hda_codec_realtek i2c_i801 i2c_core iTCO_wdt serio_raw snd_hda_intel snd_hda_codec pcspkr psmouse snd_pcm snd_timer snd button processor soundcore intel_agp snd_page_alloc evdev ext3 jbd mbcache raid10 raid456 raid6_pq async_xor async_memcpy async_tx xor raid1 raid0 multipath linear md_mod sg sr_mod sd_mod cdrom ahci libata scsi_mod tg3 libphy uhci_hcd ehci_hcd thermal fan thermal_sys
> > > > > [405816.059462] Pid: 215, comm: kswapd0 Not tainted 2.6.31-rc4 #1 N8-S720XMZCUUA2
> > > > > [405816.059504] RIP: 0010:[<ffffffff810a2ac0>]  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > > > > [405816.059554] RSP: 0018:ffff88016cec1a40  EFLAGS: 00010282
> > > > > [405816.059579] RAX: e7d50c6d4d1428d2 RBX: ffffea0003f5fbb0 RCX: 0000000000000800
> > > > > [405816.059621] RDX: 0000000000000002 RSI: 0000000000000001 RDI: 0000000000000000
> > > > > [405816.059663] RBP: ffffea0003f5fbd8 R08: 0000000000000001 R09: ffff88016fc075c0
> > > > > [405816.059705] R10: 00003ffffffff000 R11: ffff88007a26f880 R12: ffff8801506f41a8
> > > > > [405816.059747] R13: 0000000000000001 R14: 000000000000e800 R15: ffff88016cec1e10
> > > > > [405816.059789] FS:  0000000000000000(0000) GS:ffff880028028000(0000) knlGS:0000000000000000
> > > > > [405816.059833] CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
> > > > > [405816.059858] CR2: 0000000001ae9618 CR3: 000000016c802000 CR4: 00000000000406f0
> > > > > [405816.059900] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > > > > [405816.059943] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > > > > [405816.059985] Process kswapd0 (pid: 215, threadinfo ffff88016cec0000, task ffff88016f27f930)
> > > > > [405816.060028] Stack:
> > > > > [405816.060047]  0000000000000001 ffff88016cec1af0 0000000000000000 ffff88016cec1cb0
> > > > > [405816.060078] <0> 0000000000000000 0000000000000017 0000000000000009 0000000000000001
> > > > > [405816.060124] <0> ffffea00039702b8 ffffea0004aa0458 ffffea0004aa0810 ffffea0003970248
> > > > > [405816.060185] Call Trace:
> > > > > [405816.060208]  [<ffffffff8100c40e>] ? common_interrupt+0xe/0x13
> > > > > [405816.060234]  [<ffffffff810a1cdb>] ? isolate_pages_global+0xa9/0x1f3
> > > > > [405816.060262]  [<ffffffff810a338a>] ? shrink_list+0x2d8/0x5ec
> > > > > [405816.060289]  [<ffffffff8110ac52>] ? proc_delete_inode+0x0/0x40
> > > > > [405816.060317]  [<ffffffff8109f621>] ? determine_dirtyable_memory+0xd/0x1d
> > > > > [405816.060345]  [<ffffffff8109f697>] ? get_dirty_limits+0x1d/0x256
> > > > > [405816.060371]  [<ffffffff8100a54d>] ? __switch_to+0xae/0x266
> > > > > [405816.060397]  [<ffffffff810a3921>] ? shrink_zone+0x283/0x335
> > > > > [405816.060427]  [<ffffffffa0189217>] ? mb_cache_shrink_fn+0x26/0x117 [mbcache]
> > > > > [405816.060456]  [<ffffffff810a3b14>] ? shrink_slab+0x141/0x153
> > > > > [405816.060482]  [<ffffffff810a42ff>] ? kswapd+0x482/0x631
> > > > > [405816.060507]  [<ffffffff810a1c32>] ? isolate_pages_global+0x0/0x1f3
> > > > > [405816.060536]  [<ffffffff81053522>] ? autoremove_wake_function+0x0/0x2e
> > > > > [405816.060564]  [<ffffffff810a3e7d>] ? kswapd+0x0/0x631
> > > > > [405816.060588]  [<ffffffff810531d9>] ? kthread+0x84/0x8c
> > > > > [405816.060614]  [<ffffffff8100caca>] ? child_rip+0xa/0x20
> > > > > [405816.060639]  [<ffffffff81053155>] ? kthread+0x0/0x8c
> > > > > [405816.060664]  [<ffffffff8100cac0>] ? child_rip+0x0/0x20
> > > > > [405816.060688] Code: c0 0f 84 d1 02 00 00 f0 80 65 d8 ef 48 c7 c6 e0 b9 2a 81 48 c7 c7 26 fc 32 81 31 c0 e8 02 d0 1e 00 e9 b6 01 00 00 49 8b 44 24 58 <48> 83 38 00 0f 84 79 02 00 00 65 48 8b 04 25 00 b0 00 00 f6 40 
> > > > > [405816.060819] RIP  [<ffffffff810a2ac0>] shrink_page_list+0x2ac/0x609
> > > > > [405816.060847]  RSP <ffff88016cec1a40>
> > > > > [405816.061045] ---[ end trace c44a8d41c1aab2f3 ]---
> > > > > 

Re: Crash...

[Andrea Gelmini]

2009/7/27 Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>:
> Can you reproduce the bug without using lvm volume?

Hi,
   to trigger the ops I had to write a file >4G.
   Anyway, with latest Ryusuke's patch, I had no problem at all, even
with nilfs on top of MD+LVM.

Thanks a lot,
Andrea

Re: Crash...

[Jiro SEKIBA]

Hi,

At Sat, 1 Aug 2009 15:39:17 +0200,
Andrea Gelmini wrote:
> 
> 2009/7/27 Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>:
> > Can you reproduce the bug without using lvm volume?
> 
> Hi,
>    to trigger the ops I had to write a file >4G.

nhhh, I rsynced lots of DVD images, so some of those must have been >4G.

>    Anyway, with latest Ryusuke's patch, I had no problem at all, even
> with nilfs on top of MD+LVM.

That is good news, good news anyway

thanks

regards,
-- 
Jiro SEKIBA <jir-hfpbi5WX9J54Eiagz67IpQ@public.gmane.org>

Re: Crash...

[Reinoud Zandijk]

On Thu, Jul 23, 2009 at 11:02:47PM +0200, Andrea Gelmini wrote:
> 2009/7/23 Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org>:
> > It also suggests that an inconsistent state in page cache of B-tree
> > nodes hit the function; the function found a dirty page, but the page
> > didn't have buffer heads which was supposed to be impossible for the
> > b-tree of nilfs.
>    -> mkfs.nilfs2 -b 1024 /dev/mapper/VG-NilfHome (maybe the problem
> is the 1K block size?)

1024 is lower than the page size so that might explain a lot! I think its a
missing check in the mkfs.nilfs2 to never allow lower values than the page
size for block size.... but Ryusuke can better answer that :-D

With regards,
Reinoud

Re: Crash...

[Andrea Gelmini]

2009/7/24 Reinoud Zandijk <reinoud-S783fYmB3Ccdnm+yROfE0A@public.gmane.org>:
> 1024 is lower than the page size so that might explain a lot! I think its a
> missing check in the mkfs.nilfs2 to never allow lower values than the page
> size for block size.... but Ryusuke can better answer that :-D

I agree with you, but man page of mkfs.nilfs2 says it can be
1024/2048/4096/8192.
Of course it can't be > of page size, but that's a VFS problem.

Ciao,
Andrea

Re: Crash...

[Reinoud Zandijk]

On Fri, Jul 24, 2009 at 11:47:21AM +0200, Andrea Gelmini wrote:
> 2009/7/24 Reinoud Zandijk <reinoud-S783fYmB3Ccdnm+yROfE0A@public.gmane.org>:
> > 1024 is lower than the page size so that might explain a lot! I think its a
> > missing check in the mkfs.nilfs2 to never allow lower values than the page
> > size for block size.... but Ryusuke can better answer that :-D
> 
> I agree with you, but man page of mkfs.nilfs2 says it can be
> 1024/2048/4096/8192.
> Of course it can't be > of page size, but that's a VFS problem.

It could be an implementation limit or a bug in the sub-page handling... i
dont know linux that much :-S

With regards,
Reinoud

Re: Crash...

[Ryusuke Konishi]

On Fri, 24 Jul 2009 11:47:21 +0200, Andrea Gelmini wrote:
> 2009/7/24 Reinoud Zandijk <reinoud-S783fYmB3Ccdnm+yROfE0A@public.gmane.org>:
> > 1024 is lower than the page size so that might explain a lot! I think its a
> > missing check in the mkfs.nilfs2 to never allow lower values than the page
> > size for block size.... but Ryusuke can better answer that :-D
> 
> I agree with you, but man page of mkfs.nilfs2 says it can be
> 1024/2048/4096/8192.
> Of course it can't be > of page size, but that's a VFS problem.

Exactly.
 
> Ciao,
> Andrea

Cheers,
Ryusuke Konishi

Re: Crash...

[Ryusuke Konishi]

On Fri, 24 Jul 2009 10:58:03 +0200, Reinoud Zandijk <reinoud-S783fYmB3Ccdnm+yROfE0A@public.gmane.org> wrote:
> On Thu, Jul 23, 2009 at 11:02:47PM +0200, Andrea Gelmini wrote:
> > 2009/7/23 Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org>:
> > > It also suggests that an inconsistent state in page cache of B-tree
> > > nodes hit the function; the function found a dirty page, but the page
> > > didn't have buffer heads which was supposed to be impossible for the
> > > b-tree of nilfs.
> >    -> mkfs.nilfs2 -b 1024 /dev/mapper/VG-NilfHome (maybe the problem
> > is the 1K block size?)
> 
> 1024 is lower than the page size so that might explain a lot!

Yes, I suspect this in fact.  The small size block changes several
code paths.

> I think its a missing check in the mkfs.nilfs2 to never allow lower
> values than the page size for block size.... but Ryusuke can better
> answer that :-D
>
> With regards,
> Reinoud
 
We have implemented nilfs to allow smaller block sizes in order to
support some devices such like DVD/CD-ROM or flash based ones.

So, I count it a bug which we should fix.

Thanks,
Ryusuke Konishi

Re: Crash...

[Reinoud Zandijk]

Hi Ryusuke,

On Fri, Jul 24, 2009 at 07:46:17PM +0900, Ryusuke Konishi wrote:
> We have implemented nilfs to allow smaller block sizes in order to
> support some devices such like DVD/CD-ROM or flash based ones.

sounds fine :) i had some ideas about using NiLFS on CD-R/DVD*R and some ideas
about refining NiLFS on flash based media.

For CD-R/DVD*R the last block written (or written several times) can be the
superblock so sequential media will work just fine. No use for a garbage
collector there ;)

For flash media, the entire first segment/erase block can be used to store the
superblock in; filling it up sequentially and when full, trigger the erase
block wiping :)

Idea?

With regards,
Reinoud

Re: Crash...

[Ryusuke Konishi]

Hi,
On Fri, 24 Jul 2009 13:13:33 +0200, Reinoud Zandijk wrote:
> Hi Ryusuke,
> 
> On Fri, Jul 24, 2009 at 07:46:17PM +0900, Ryusuke Konishi wrote:
> > We have implemented nilfs to allow smaller block sizes in order to
> > support some devices such like DVD/CD-ROM or flash based ones.
> 
> sounds fine :) i had some ideas about using NiLFS on CD-R/DVD*R and some ideas
> about refining NiLFS on flash based media.
> 
> For CD-R/DVD*R the last block written (or written several times) can be the
> superblock so sequential media will work just fine. No use for a garbage
> collector there ;)

I didn't mean the on-the-fly burning, but it sounds interesting.

NILFS already has the secondary superblock in tail of the device, so
it seems achievable by adjusting writeback of two superblocks.

It sounds like UDF except that NILFS allows snapshot access
though even UDF seems to be capable of restoring past data in theory.
(I dunno if it can in reality)
 
> For flash media, the entire first segment/erase block can be used to store the
> superblock in; filling it up sequentially and when full, trigger the erase
> block wiping :)
> 
> Idea?
>
> With regards,
> Reinoud

Sounds nice.

I have a pending patch in the experimental tree which allows nilfs to
issue erase commands to the segment GC reclaimed.  But, I felt it
lacks something needed by flash devices.

If we add a ssd mount option to nilfs, I think this sort of ingenuity
to increase the lifespan of the device should be taken in.

Cheers,
Ryusuke Konishi

Re: Crash...

[Ryusuke Konishi]

[-- Attachment #1: Type: Text/Plain, Size: 2262 bytes --]

Hi Andrea,
On Thu, 23 Jul 2009 23:02:47 +0200, Andrea Gelmini wrote:
> 2009/7/23 Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org>:
> > It also suggests that an inconsistent state in page cache of B-tree
> > nodes hit the function; the function found a dirty page, but the page
> > didn't have buffer heads which was supposed to be impossible for the
> > b-tree of nilfs.
> 
> Well,
>    thanks for your quick reply.
>    Anyway, I can reproduce the same problem doing same things with
> stable kernel (2.6.29.6) and nilfs2-module from git repository.
>    I do this:
>    -> mkfs.nilfs2 -b 1024 /dev/mapper/VG-NilfHome (maybe the problem
> is the 1K block size?)
>    -> mount /dev/mapper/VG-NilfHome /tmp/test/
>    -> I run mirrordir (here's exactly as a "cp -a")
> 
>    It stucks at the same file as the crash before.
>    It's a 5G file, if it could help.

I found a bug which may cause the kernel oops you reported.
The bug can arise only if buffer size is smaller than page size.

Here I attach the patch that will hopefully fix this problem.

Could you test if the patch makes a difference for the same file ?

Regards,
Ryusuke Konishi
---
 fs/nilfs2/segment.c |   16 +++++++++++++++-
 1 files changed, 15 insertions(+), 1 deletions(-)

diff --git a/fs/nilfs2/segment.c b/fs/nilfs2/segment.c
index 8b5e477..51ff3d0 100644
--- a/fs/nilfs2/segment.c
+++ b/fs/nilfs2/segment.c
@@ -1859,12 +1859,26 @@ static void nilfs_end_page_io(struct page *page, int err)
 	if (!page)
 		return;
 
-	if (buffer_nilfs_node(page_buffers(page)) && !PageWriteback(page))
+	if (buffer_nilfs_node(page_buffers(page)) && !PageWriteback(page)) {
 		/*
 		 * For b-tree node pages, this function may be called twice
 		 * or more because they might be split in a segment.
 		 */
+		if (PageDirty(page)) {
+			/*
+			 * For pages holding split b-tree node buffers, dirty
+			 * flag on the buffers may be cleared discretely.
+			 * In that case, the page is once redirtied for
+			 * remaining buffers, and it must be cancelled if
+			 * all the buffers get cleaned later.
+			 */
+			lock_page(page);
+			if (nilfs_page_buffers_clean(page))
+				__nilfs_clear_page_dirty(page);
+			unlock_page(page);
+		}
 		return;
+	}
 
 	__nilfs_end_page_io(page, err);
 }
-- 
1.6.3.3


[-- Attachment #2: nilfs2-fix-oops-due-to-inconsistent-page-state.patch.bz2 --]
[-- Type: Application/Octet-Stream, Size: 1128 bytes --]

[-- Attachment #3: Type: text/plain, Size: 158 bytes --]

_______________________________________________
users mailing list
users-JrjvKiOkagjYtjvyW6yDsg@public.gmane.org
https://www.nilfs.org/mailman/listinfo/users

Re: Crash...

[Andrea Gelmini]

2009/7/29 Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org>:
> Could you test if the patch makes a difference for the same file ?

Well,
   I used this:
   git://git.kernel.org/pub/scm/linux/kernel/git/ryusuke/nilfs2.git
(branch fixes)

   I stressed it a lot, and it works perfectly.
   In a few days I will test the 2048 block size, too (even I guess
it's not necessary).

Thanks a lot for your work,
Andrea

Re: Crash...

[Ryusuke Konishi]

On Sat, 1 Aug 2009 15:36:22 +0200, Andrea Gelmini wrote:
> 2009/7/29 Ryusuke Konishi <ryusuke-sG5X7nlA6pw@public.gmane.org>:
> > Could you test if the patch makes a difference for the same file ?
> 
> Well,
>    I used this:
>    git://git.kernel.org/pub/scm/linux/kernel/git/ryusuke/nilfs2.git
> (branch fixes)
> 
>    I stressed it a lot, and it works perfectly.
>    In a few days I will test the 2048 block size, too (even I guess
> it's not necessary).
> 
> Thanks a lot for your work,
> Andrea

Thanks for your response.
I will send the fix to Linus for the next -rc release.

Thanks,
Ryusuke Konishi