Hi, i just wanted to know from people that know about mm/fs subject,
if the follow
"oops" its an expected behavior (kinda feature ) or not, since i was
just touching some files and suddenly started to happen. Please CC me
since i am not subscribed to the list.
I consider myself ignorant about this subject to make any asumption,
so i'll try to explain what's going on.
Using lastest git kernel (2.6.30-6701-g4b67c5d), and also tested on
2.6.28-rc2 both smp.
(Modules: jbd2 )
No "oops" reported when:
Booting with slub_debug=ZPU , the caches are not merged, so doing
something like this
# modprobe jbd2 ( or ext4 )
# ls -la /sys/kernel/slab|grep jbd2
...
drwxr-xr-x 2 root root 0 Jun 20 20:50 jbd2_journal_handle
drwxr-xr-x 2 root root 0 Jun 20 20:50 jbd2_journal_head
drwxr-xr-x 2 root root 0 Jun 20 20:50 jbd2_revoke_record
drwxr-xr-x 2 root root 0 Jun 20 20:50 jbd2_revoke_table
....
Next, when removing the module: (rmmod jbd2 or modprobe -r ext4 ),
the jbd2_* files
are removed from sys.
But, when booting with slub_debug=- ( or disabling slub debug directly
from kernel ), the caches are merged , so after modprobe ext4 (or
jbd2) /sys/kernel/slab|grep jbd2 reports something like:
lrwxrwxrwx 1 root root 0 Jun 20 21:00 jbd2_journal_handle -> :at-0000040
lrwxrwxrwx 1 root root 0 Jun 20 21:00 jbd2_journal_head -> :at-0000064
lrwxrwxrwx 1 root root 0 Jun 20 21:00 jbd2_revoke_record -> :at-0000032
lrwxrwxrwx 1 root root 0 Jun 20 21:00 jbd2_revoke_table -> :at-0000016
slabinfo -a reports:
-------------------------------
:at-0000016 <- revoke_record revoke_table jbd2_revoke_table
:at-0000040 <- jbd2_journal_handle journal_handle ext4_free_block_extents
:at-0000048 <- ext3_xattr ext2_xattr ext4_xattr
:at-0000064 <- journal_head jbd2_journal_head
:t-0000008 <- kmalloc-8 dm_rq_clone_bio_info
:t-0000016 <- inotify_event_private_data kmalloc-16 ip_fib_alias
dm_target_io dm_snap_tracked_chunk fsnotify_event_holder fasync_cache
:t-0000024 <- Acpi-Namespace dm_io debug_objects_cache
dm_snap_exception dnotify_struct scsi_data_buffer nsproxy
:t-0000032 <- kmalloc-32 fib6_nodes tcp_bind_bucket uhci_urb_priv
secpath_cache Acpi-Parse
:t-0000040 <- Acpi-Operand ip_fib_hash eventpoll_pwq
:t-0000048 <- Acpi-ParseExt sysfs_dir_cache Acpi-State
:t-0000064 <- inet_peer_cache dm_snap_pending_exception uid_cache
pid nfs_page kmalloc-64
:t-0000080 <- blkdev_ioc flow_cache
:t-0000096 <- inotify_inode_mark_entry cfq_io_context fsnotify_event
kmalloc-96 dnotify_mark_entry
:t-0000128 <- request_sock_TCP ip_mrt_cache mnt_cache cred_jar bio-0
scsi_sense_cache eventpoll_epi request_sock_TCPv6 kmalloc-128
:t-0000192 <- kiocb biovec-16 skbuff_head_cache kmalloc-192
scsi_cmd_cache filp key_jar rpc_tasks sgpool-8
:t-0000256 <- arp_cache kmalloc-256 ndisc_cache ip6_dst_cache ip_dst_cache
:t-0000320 <- sgpool-16 xfrm_dst_cache
:t-0000384 <- kioctx nfs_read_data skbuff_fclone_cache
:t-0000768 <- biovec-64 RAW
:t-0002048 <- kmalloc-2048 rpc_buffers
:t-0004096 <- names_cache kmalloc-4096
-------[eof]-------
Now , when modprobe -r ext4 ( or rmmod jbd2), the jbd2_* files are
still listed on /sys/kernel/slab
and slabinfo start to report some alias errors. I suppose they are not
remove if they have been merged on some cache that's still being used
by some "alias" or if they have persistent in-kernel storage.
Since the "alias" or files are still listed, when doing:
# echo 1 > /sys/kernel/slab/jbd2_journal_handle/poison
# modprobe ext4 ( or modprobe jbd2 )
this oops appears and later a bunch of another oops, making the system
unresponsive.
[ 65.132850] ------------[ cut here ]------------
[ 65.132925] WARNING: at fs/sysfs/dir.c:487 sysfs_add_one+0xf6/0x120()
[ 65.132989] Hardware name: Extensa 5420
[ 65.133069] sysfs: cannot create duplicate filename
'/kernel/slab/:at-0000040'
[ 65.133154] Modules linked in: jbd2(+) crc16 loop
snd_hda_codec_realtek snd_hda_intel snd_hda_codec arc4 ecb snd_hwdep
cryptomgr aead snd_pcm_oss snd_pcm pcompress crypto_blkcipher
snd_mixer_oss crypto_hash crypto_algapi snd_seq_oss $
[ 65.135932] Pid: 4507, comm: modprobe Tainted: G B
2.6.30-obelisco-generic #29
[ 65.136026] Call Trace:
[ 65.136087] [<c113b566>] ? sysfs_add_one+0xf6/0x120
[ 65.136151] [<c1042c9d>] warn_slowpath_common+0x7d/0xe0
[ 65.136215] [<c113b566>] ? sysfs_add_one+0xf6/0x120
[ 65.136278] [<c1042d73>] warn_slowpath_fmt+0x33/0x50
[ 65.136341] [<c113b566>] sysfs_add_one+0xf6/0x120
[ 65.136403] [<c113bc6a>] create_dir+0x5a/0xb0
[ 65.136465] [<c113bcf6>] sysfs_create_dir+0x36/0x60
[ 65.136530] [<c14cd4fb>] ? _spin_unlock+0x2b/0x50
[ 65.136595] [<c11c69b4>] kobject_add_internal+0xd4/0x1d0
[ 65.136659] [<c11c6bdd>] kobject_add_varg+0x3d/0x70
[ 65.136721] [<c11c6c4e>] kobject_init_and_add+0x3e/0x60
[ 65.136785] [<c10e1772>] sysfs_slab_add+0x82/0x220
[ 65.136849] [<c10e1b38>] kmem_cache_create+0xe8/0x2f0
[ 65.137716] [<f8ae80b5>] ? journal_init+0x0/0xd5 [jbd2]
[ 65.137782] [<f8ae8153>] journal_init+0x9e/0xd5 [jbd2]
[ 65.137845] [<c1001155>] do_one_initcall+0x35/0x180
[ 65.137909] [<c1063b54>] ? up_read+0x24/0x50
[ 65.137972] [<c1064993>] ? __blocking_notifier_call_chain+0x63/0x90
[ 65.138047] [<c10649e7>] ? blocking_notifier_call_chain+0x27/0x50
[ 65.138111] [<c10850a2>] sys_init_module+0xc2/0x210
[ 65.138175] [<c10032ef>] sysenter_do_call+0x12/0x3c
[ 65.138237] ---[ end trace 16c86c85e40c183d ]---
[ 65.138301] kobject_add_internal failed for :at-0000040 with
-EEXIST, don't try to register things with the same name in the same
directory.
[ 65.138390] Pid: 4507, comm: modprobe Tainted: G B W
2.6.30-obelisco-generic #29
[ 65.138474] Call Trace:
[ 65.138534] [<c14c99d3>] ? printk+0x23/0x40
[ 65.138596] [<c11c69f8>] kobject_add_internal+0x118/0x1d0
[ 65.138660] [<c11c6bdd>] kobject_add_varg+0x3d/0x70
[ 65.138722] [<c11c6c4e>] kobject_init_and_add+0x3e/0x60
[ 65.138786] [<c10e1772>] sysfs_slab_add+0x82/0x220
[ 65.138848] [<c10e1b38>] kmem_cache_create+0xe8/0x2f0
[ 65.138913] [<f8ae80b5>] ? journal_init+0x0/0xd5 [jbd2]
[ 65.138979] [<f8ae8153>] journal_init+0x9e/0xd5 [ 65.139243]
[<c10649e7>] ? blocking_notifier_call_chain+0x27/0x50
[ 65.139307] [<c10850a2>] sys_init_module+0xc2/0x210
[ 65.139369] [<c10032ef>] sysenter_do_call+0x12/0x3c
[ 65.141247] BUG: unable to handle kernel NULL pointer dereference at (null)
[ 65.141396] IP: [<c11d46a7>] list_del+0x17/0xb0
[ 65.141500] *pde = 00000000
[ 65.141597] Oops: 0000 [#1] SMP
[ 65.141732] last sysfs file: /sys/kernel/slab/:at-0000040/poison
[ 65.141795] Modules linked in: jbd2(+) crc16 loop
snd_hda_codec_realtek snd_hda_intel snd_hda_codec arc4 ecb snd_hwdep
cryptomgr aead snd_pcm_oss snd_pcm pcompress crypto_blkcipher
snd_mixer_oss crypto_hash crypto_algapi snd_seq_oss $
[ 65.142015]
[ 65.142015] Pid: 4507, comm: modprobe Tainted: G B W
(2.6.30-obelisco-generic #29) Extensa 5420
[ 65.142015] EIP: 0060:[<c11d46a7>] EFLAGS: 00010246 CPU: 0
[ 65.142015] EIP is at list_del+0x17/0xb0
[ 65.142015] EAX: 00000000 EBX: f7374df8 ECX: 00000000 EDX: 00000000
[ 65.142015] ESI: f7374d80 EDI: f8ae0416 EBP: c3633ea0 ESP: c3633e84
[ 65.142015] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 65.142015] Process modprobe (pid: 4507, ti=c3632000 task=c3a0c060
task.ti=c3632000)
[ 65.142015] Stack:
[ 65.142015] 00000002 00000000 c10e1b46 fc41b58e f7374d80 fc41b58e
f7374d80 c3633ef0
[ 65.142015] <0> c10e1b4e 00000028 00000000 00020000 00000000
00000000 00020000 00000000
[ 65.142015] <0> 00000028 f7374df8 00000000 00000005 0000002b
fffffff8 00020000 fc41b58e
[ 65.142015] Call Trace:
[ 65.142015] [<c10e1b46>] ? kmem_cache_create+0xf6/0x2f0
[ 65.142015] [<c10e1b4e>] ? kmem_cache_create+0xfe/0x2f0
[ 65.142015] [<f8ae80b5>] ? journal_init+0x0/0xd5 [jbd2]
[ 65.142015] [<f8ae8153>] ? journal_init+0x9e/0xd5 [jbd2]
[ 65.142015] [<c1001155>] ? do_one_initcall+0x35/0x180
[ 65.142015] [<c1063b54>] ? up_read+0x24/0x50
[ 65.142015] [<c1064993>] ? __blocking_notifier_call_chain+0x63/0x90
[ 65.142015] [<c10649e7>] ? blocking_notifier_call_chain+0x27/0x50
[ 65.142015] [<c10850a2>] ? sys_init_module+0xc2/0x210
[ 65.142015] [<c10032ef>] ? sysenter_do_call+0x12/0x3c
[ 65.142015] Code: 75 fc 89 ec 5d c3 e8 f9 e7 e6 ff 90 90 90 90 90
90 90 90 90 55 89 e5 53 89 c3 83 ec 18 65 a1 14 00 00 00 89 45 f8 31
c0 8b 43 04 <8b> 00 39 d8 75 5d 8b 13 8b 42 04 39 d8 75 2c 8b 43 04 89
42 04
[ 65.142015] EIP: [<c11d46a7>] list_del+0x17/0xb0 SS:ESP 0068:c3633e84
[ 65.142015] CR2: 0000000000000000
[ 65.149731] ---[ end trace 16c86c85e40c183e ]---
[jbd2]
[ 65.139053] [<c1001155>] do_one_initcall+0x35/0x180
[ 65.139116] [<c1063b54>] ? up_read+0x24/0x50
[ 65.139179] [<c1064993>] ? __blocking_notifier_call_chain+0x63/0x90
[more oops, related to other operations]
So to resume all the wrong assumptions i wrote, this is reproducible
in my case doing:
#modprobe jbd2 ( or any dependent module)
#rmmod jbd2 ( or any dependent module, [-r] in that case )
#echo 1 > /sys/kernel/slab/jbd2_journal_handle/poison
#modprobe jbd2
Is this "behavior" expected since the caches are merged? or i am just
writing bs and its related to another thing?
Best Rgds
Sorry if i make some ppl loose time reading this.
Costantino Leandro
--
To unsubscribe from this list: send the line "unsubscribe linux-fsdevel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
