2.6.13-rc4 use after free in class_device_attr_show

2.6.13-rc4 use after free in class_device_attr_show

[Keith Owens]

2.6.13-rc4 + kdb, with lots of CONFIG_DEBUG options.  There is an
intermittent use after free in class_device_attr_show.  Reboot with no
changes and the problem does not always recur.

Starting SSH daemon                                                   done
Starting sound driver                                                 done
Starting cupsd                                                        done
loading ACPI modules () Starting powersaved                           done
Try to get initial date and time via NTP from  ntp0                   done
Starting network time protocol daemon (NTPD)                          done
Starting kernel based NFS server                                      done
Starting service automounter                                          done
udev[21369]: Oops 8813272891392 [1]

udev[21369]: Oops 8813272891392 [1]
Modules linked in: md5 ipv6 usbcore raid0 md_mod nls_iso8859_1 nls_cp437 dm_mod sg st osst

Pid: 21369, CPU 0, comm:                 udev
psr : 00001010081a6018 ifs : 8000000000000308 ip  : [<a0000001005807b0>]    Not tainted
ip is at class_device_attr_show+0x50/0xa0
unat: 0000000000000000 pfs : 0000000000000711 rsc : 0000000000000003
rnat: a000000100abbae0 bsps: 00000000000001fb pr  : 0000000000159659
ldrs: 0000000000000000 ccv : 0000000000000000 fpsr: 0009804c0270033f
csd : 0000000000000000 ssd : 0000000000000000
b0  : a00000010025def0 b6  : a00000010000e8c0 b7  : a000000100580760
f6  : 1003e6db6db6db6db6db7 f7  : 1003e0000000000c1d6ca
f8  : 1003e0000000000c1d6ca f9  : 1003e00000000054cdf86
f10 : 000000000000000000000 f11 : 000000000000000000000
r1  : a000000100ddf0a0 r2  : e000003072ab7288 r3  : e00000300301c498
r8  : 0000000000000000 r9  : a000000100bfb5d0 r10 : e000003075b28000
r11 : 0000000000c1d6ca r12 : e000003076ce7e20 r13 : e000003076ce0000
r14 : a000000100580760 r15 : e000003075b28000 r16 : 6db6db6db6db6db7
r17 : 000000002a66fc30 r18 : a0007fff62138000 r19 : e0000030030102c8
r20 : e000003003010000 r21 : fffffffffffefcf1 r22 : 0000000000000010
r23 : a000000100d46c50 r24 : a000000100bfb5d0 r25 : 00000000054cdf86
r26 : a0000001009968c8 r27 : e000003003015208 r28 : 0000000000000000
r29 : e000003003010000 r30 : a000000100d46c50 r31 : 0000000000000000

Call Trace:
 [<a000000100011f80>] show_stack+0x80/0xa0
                                sp=e000003076ce79c0 bsp=e000003076ce10d8
 [<a0000001000127f0>] show_regs+0x850/0x880
                                sp=e000003076ce7b90 bsp=e000003076ce1078
 [<a00000010003c000>] die+0x280/0x4a0
                                sp=e000003076ce7ba0 bsp=e000003076ce1028
 [<a000000100060ad0>] ia64_do_page_fault+0x650/0xba0
                                sp=e000003076ce7ba0 bsp=e000003076ce0fb8
 [<a00000010000b6c0>] ia64_leave_kernel+0x0/0x290
                                sp=e000003076ce7c50 bsp=e000003076ce0fb8
 [<a0000001005807b0>] class_device_attr_show+0x50/0xa0
                                sp=e000003076ce7e20 bsp=e000003076ce0f78
 [<a00000010025def0>] sysfs_read_file+0x2b0/0x360
                                sp=e000003076ce7e20 bsp=e000003076ce0f08
 [<a000000100198a40>] vfs_read+0x1c0/0x360
                                sp=e000003076ce7e20 bsp=e000003076ce0eb0
 [<a000000100198d80>] sys_read+0x80/0xe0
                                sp=e000003076ce7e20 bsp=e000003076ce0e38
 [<a00000010000b520>] ia64_ret_from_syscall+0x0/0x20
                                sp=e000003076ce7e30 bsp=e000003076ce0e38
kdb> id class_device_attr_show
0xa000000100580760 class_device_attr_show[MII]       alloc r36=ar.pfs,8,6,0
0xa000000100580766 class_device_attr_show+0x6            mov r8=r0;;
0xa00000010058076c class_device_attr_show+0xc            adds r2=24,r33

0xa000000100580770 class_device_attr_show+0x10[MMI]       mov r37=r1
0xa000000100580776 class_device_attr_show+0x16            mov r39=r34
0xa00000010058077c class_device_attr_show+0x1c            adds r38=-16,r32

0xa000000100580780 class_device_attr_show+0x20[MII]       nop.m 0x0
0xa000000100580786 class_device_attr_show+0x26            mov r35=b0;;
0xa00000010058078c class_device_attr_show+0x2c            mov.i ar.pfs=r36

0xa000000100580790 class_device_attr_show+0x30[MII]       ld8 r33=[r2]
0xa000000100580796 class_device_attr_show+0x36            mov b0=r35;;
0xa00000010058079c class_device_attr_show+0x3c            cmp.eq p8,p9=0,r33

0xa0000001005807a0 class_device_attr_show+0x40[MBB]       nop.m 0x0
0xa0000001005807a6 class_device_attr_show+0x46      (p09) br.cond.dpnt.few 0xa0000001005807b0 class_device_attr_show+0x50
0xa0000001005807ac class_device_attr_show+0x4c            br.ret.sptk.many b0

0xa0000001005807b0 class_device_attr_show+0x50[MMI]       ld8 r8=[r33],8;;
0xa0000001005807b6 class_device_attr_show+0x56            ld8 r1=[r33],-8
0xa0000001005807bc class_device_attr_show+0x5c            mov b7=r8

0xa0000001005807c0 class_device_attr_show+0x60[MIB]       nop.m 0x0
0xa0000001005807c6 class_device_attr_show+0x66            nop.i 0x0
0xa0000001005807cc class_device_attr_show+0x6c            br.call.sptk.many b0=b7;;

0xa0000001005807d0 class_device_attr_show+0x70[MII]       mov r1=r37
0xa0000001005807d6 class_device_attr_show+0x76            mov.i ar.pfs=r36
0xa0000001005807dc class_device_attr_show+0x7c            mov b0=r35

kdb> r s
 r32: e00000b4793c37e8  r33: 6b6b6b6b6b6b6b6b  r34: e000003075b28000
 r35: a00000010025def0  r36: 0000000000000711  r37: a000000100ddf0a0
 r38: e00000b4793c37d8  r39: e000003075b28000
kdb> mds 0xe000003072ab7288
0xe000003072ab7288 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003072ab7290 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003072ab7298 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003072ab72a0 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003072ab72a8 a56b6b6b6b6b6b6b   kkkkkkk.
0xe000003072ab72b0 5a2cf071   q.,Z....
0xe000003072ab72b8 a000000100459640 linvfs_follow_link+0x1e0
0xe000003072ab72c0 5a2cf071   q.,Z....
[<a000000000010640>] __kernel_syscall_via_break+0x0/
                                sp=e000003076ce8000 bsp=e000003076ce0e38

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Andrew Morton]

Keith Owens <kaos@sgi.com> wrote:
>
> 2.6.13-rc4 + kdb, with lots of CONFIG_DEBUG options.  There is an
>  intermittent use after free in class_device_attr_show.  Reboot with no
>  changes and the problem does not always recur.
> ...
>  ip is at class_device_attr_show+0x50/0xa0
> ...
> 
>  Call Trace:
>   [<a000000100011f80>] show_stack+0x80/0xa0
>                                  sp=e000003076ce79c0 bsp=e000003076ce10d8
>   [<a0000001000127f0>] show_regs+0x850/0x880
>                                  sp=e000003076ce7b90 bsp=e000003076ce1078
>   [<a00000010003c000>] die+0x280/0x4a0
>                                  sp=e000003076ce7ba0 bsp=e000003076ce1028
>   [<a000000100060ad0>] ia64_do_page_fault+0x650/0xba0
>                                  sp=e000003076ce7ba0 bsp=e000003076ce0fb8
>   [<a00000010000b6c0>] ia64_leave_kernel+0x0/0x290
>                                  sp=e000003076ce7c50 bsp=e000003076ce0fb8
>   [<a0000001005807b0>] class_device_attr_show+0x50/0xa0
>                                  sp=e000003076ce7e20 bsp=e000003076ce0f78
>   [<a00000010025def0>] sysfs_read_file+0x2b0/0x360
>                                  sp=e000003076ce7e20 bsp=e000003076ce0f08
>   [<a000000100198a40>] vfs_read+0x1c0/0x360
>                                  sp=e000003076ce7e20 bsp=e000003076ce0eb0
>   [<a000000100198d80>] sys_read+0x80/0xe0
>                                  sp=e000003076ce7e20 bsp=e000003076ce0e38
>   [<a00000010000b520>] ia64_ret_from_syscall+0x0/0x20
>                                  sp=e000003076ce7e30 bsp=e000003076ce0e38

It might help to know which file is being read from here.

The below patch will record the name of the most-recently-opened sysfs
file.  You can print last_sysfs_file[] in the debugger or add the
appropriate printk to the ia64 code?

--- devel/fs/sysfs/file.c~sysfs-crash-debugging	2005-07-30 01:32:10.000000000 -0700
+++ devel-akpm/fs/sysfs/file.c	2005-07-30 02:09:01.000000000 -0700
@@ -6,6 +6,8 @@
 #include <linux/fsnotify.h>
 #include <linux/kobject.h>
 #include <linux/namei.h>
+#include <linux/limits.h>
+
 #include <asm/uaccess.h>
 #include <asm/semaphore.h>
 
@@ -324,8 +326,14 @@ static int check_perm(struct inode * ino
 	return error;
 }
 
+char last_sysfs_file[PATH_MAX];
+
 static int sysfs_open_file(struct inode * inode, struct file * filp)
 {
+	char *p = d_path(filp->f_dentry, sysfs_mount, last_sysfs_file,
+			sizeof(last_sysfs_file));
+	if (p)
+		memmove(last_sysfs_file, p, strlen(p));
 	return check_perm(inode,filp);
 }
 
diff -puN arch/i386/kernel/traps.c~sysfs-crash-debugging arch/i386/kernel/traps.c
--- devel/arch/i386/kernel/traps.c~sysfs-crash-debugging	2005-07-30 01:32:10.000000000 -0700
+++ devel-akpm/arch/i386/kernel/traps.c	2005-07-30 01:32:10.000000000 -0700
@@ -96,6 +96,8 @@ static int kstack_depth_to_print = 24;
 struct notifier_block *i386die_chain;
 static DEFINE_SPINLOCK(die_notifier_lock);
 
+extern char last_sysfs_file[];
+
 int register_die_notifier(struct notifier_block *nb)
 {
 	int err = 0;
@@ -370,6 +372,7 @@ void die(const char * str, struct pt_reg
 #endif
 		if (nl)
 			printk("\n");
+		printk(KERN_ALERT "last sysfs file: %s\n", last_sysfs_file);
 #ifdef CONFIG_KGDB
 	/* This is about the only place we want to go to kgdb even if in
 	 * user mode.  But we must go in via a trap so within kgdb we will
_

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Keith Owens]

On Sat, 30 Jul 2005 02:29:55 -0700,
Andrew Morton <akpm@osdl.org> wrote:
>Keith Owens <kaos@sgi.com> wrote:
>>
>> 2.6.13-rc4 + kdb, with lots of CONFIG_DEBUG options.  There is an
>>  intermittent use after free in class_device_attr_show.  Reboot with no
>>  changes and the problem does not always recur.
>> ...
>>  ip is at class_device_attr_show+0x50/0xa0
>> ...
>
>It might help to know which file is being read from here.
>
>The below patch will record the name of the most-recently-opened sysfs
>file.  You can print last_sysfs_file[] in the debugger or add the
>appropriate printk to the ia64 code?

No need for a patch.  It is /dev/vcsa2.

kdb> bt
Stack traceback for pid 23066
0xe00000301abf8000    23066    23051  1    0   R  0xe00000301abf8300 *udev
0xa00000010057f850 class_device_attr_show+0x50
        args (0xe00000b006abb900, 0x6b6b6b6b6b6b6b6b, 0xe0000030186d4000, 0xa00000010025cf90, 0x711)
0xa00000010025cf90 sysfs_read_file+0x2b0
        args (0xe000003073917110, 0x6000000000058210, 0x4000, 0xe00000301abffe38, 0xe00000307a98d668)
0xa000000100197ae0 vfs_read+0x1c0
        args (0xe00000301b2ba8d0, 0x6000000000058210, 0x4000, 0xe00000301abffe38, 0xe00000301b2ba8f0)
0xa000000100197e20 sys_read+0x80
        args (0x6, 0x6000000000058210, 0x4000, 0x280, 0x0)
0xa00000010000b520 ia64_ret_from_syscall
        args (0x6, 0x6000000000058210, 0x4000)
0xa000000000010640 __kernel_syscall_via_break
        args (0x6, 0x6000000000058210, 0x4000)

kdb> r
 psr: 0x00001010081a6018   ifs: 0x8000000000000308    ip: 0xa00000010057f850
unat: 0x0000000000000000   pfs: 0x0000000000000711   rsc: 0x0000000000000003
rnat: 0xa000000100abbb40  bsps: 0x000000000000036a    pr: 0x0000000000159659
ldrs: 0x0000000000000000   ccv: 0x0000000000000000  fpsr: 0x0009804c0270033f
  b0: 0xa00000010025cf90    b6: 0xa00000010000e8c0    b7: 0xa00000010057f800
  r1: 0xa000000100ddf690    r2: 0xe000003073917128    r3: 0xe000003003018498
  r8: 0x0000000000000000    r9: 0xa000000100bfbbe8   r10: 0xe0000030186d4000
 r11: 0x0000000000c061b5   r12: 0xe00000301abffe20   r13: 0xe00000301abf8000
 r14: 0xa00000010057f800   r15: 0xe0000030186d4000   r16: 0x6db6db6db6db6db7
 r17: 0x000000002a155f98   r18: 0xa0007fff62138000   r19: 0xe0000030030102c8
 r20: 0xe000003003010000   r21: 0xfffffffffffefcf1   r22: 0x0000000000000010
 r23: 0xa000000100d3f1a0   r24: 0xa000000100bfbbe8   r25: 0x000000000542abf3
 r26: 0xa000000100995718   r27: 0xe000003003015208   r28: 0x0000000000000000
 r29: 0xe000003003010000   r30: 0xa000000100d3f1a0   r31: 0x0000000000000000
&regs = e00000301abffc60

kdb> r s
 r32: e00000b006abb900  r33: 6b6b6b6b6b6b6b6b  r34: e0000030186d4000
 r35: a00000010025cf90  r36: 0000000000000711  r37: a000000100ddf690
 r38: e00000b006abb8f0  r39: e0000030186d4000

kdb> filp 0xe00000301b2ba8d0
name.name 0xe00000301aced384  name.len  3
File Pointer at 0xe00000301b2ba8d0
 f_list.nxt = 0xe00000301b2bb9e0 f_list.prv = 0xe000003003e5aeb8
 f_dentry = 0xe00000301aced2a0 f_op = 0xa000000100a615c8
 f_count = 1 f_flags = 0x8000 f_mode = 0xd
 f_pos = 0

kdb> dentry 0xe00000301aced2a0
Dentry at 0xe00000301aced2a0
 d_name.len = 3 d_name.name = 0xe00000301aced384 <dev>
 d_count = 1 d_flags = 0x18 d_inode = 0xe00000b4796a87c8
 d_parent = 0xe00000b0044a6020
 d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000200200
 d_lru.nxt = 0xe00000301aced2f8 d_lru.prv = 0xe00000301aced2f8
 d_child.nxt = 0xe00000b0044a6098 d_child.prv = 0xe00000b0044a6098
 d_subdirs.nxt = 0xe00000301aced318 d_subdirs.prv = 0xe00000301aced318
 d_alias.nxt = 0xe00000b4796a87f8 d_alias.prv = 0xe00000b4796a87f8
 d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58

kdb> inode 0xe00000b4796a87c8
struct inode at  0xe00000b4796a87c8
 i_ino = 33036 i_count = 1 i_size 16384
 i_mode = 0100444  i_nlink = 0  i_rdev = 0x0
 i_hash.nxt = 0x0000000000000000 i_hash.pprev = 0x0000000000000000
 i_list.nxt = 0xe00000301b10d2f0 i_list.prv = 0xe00000b474f1bb50
 i_dentry.nxt = 0xe00000301aced2a0 i_dentry.prv = 0xe00000301aced2a0
 i_sb = 0xe000003003e5ad58 i_op = 0xa000000100a61488 i_data = 0xe00000b4796a8970 nrpages = 0
 i_fop= 0xa000000100a615c8 i_flock = 0x0000000000000000 i_mapping = 0xe00000b4796a8970
 i_flags 0x0 i_state 0x0 []  fs specific info @ 0xe00000b4796a8b20

kdb> kobject 0xe00000b006abb900
kobject at 0xe00000b006abb900
 k_name 0xe00000b006abb908 'vcsa2'
 kref.refcount 1'
 entry.next = 0xe00000b006abb920 entry.prev = 0xe00000b006abb920
 parent = 0xe00000347b877528 kset = 0xa000000100abba30 ktype = 0x0000000000000000 dentry = 0xe00000b0044a6020

The attr is passed to class_device_attr_show in r33 but gcc has reused
that register by the time of the oops.

kdb> id class_device_attr_show
0xa00000010057f800 class_device_attr_show[MII]       alloc r36=ar.pfs,8,6,0
0xa00000010057f806 class_device_attr_show+0x6            mov r8=r0;;
0xa00000010057f80c class_device_attr_show+0xc            adds r2=24,r33

0xa00000010057f810 class_device_attr_show+0x10[MMI]       mov r37=r1
0xa00000010057f816 class_device_attr_show+0x16            mov r39=r34
0xa00000010057f81c class_device_attr_show+0x1c            adds r38=-16,r32

0xa00000010057f820 class_device_attr_show+0x20[MII]       nop.m 0x0
0xa00000010057f826 class_device_attr_show+0x26            mov r35=b0;;
0xa00000010057f82c class_device_attr_show+0x2c            mov.i ar.pfs=r36

0xa00000010057f830 class_device_attr_show+0x30[MII]       ld8 r33=[r2]
0xa00000010057f836 class_device_attr_show+0x36            mov b0=r35;;
0xa00000010057f83c class_device_attr_show+0x3c            cmp.eq p8,p9=0,r33

0xa00000010057f840 class_device_attr_show+0x40[MBB]       nop.m 0x0
0xa00000010057f846 class_device_attr_show+0x46      (p09) br.cond.dpnt.few 0xa00000010057f850 class_device_attr_show+0x50
0xa00000010057f84c class_device_attr_show+0x4c            br.ret.sptk.many b0

0xa00000010057f850 class_device_attr_show+0x50[MMI]       ld8 r8=[r33],8;;
0xa00000010057f856 class_device_attr_show+0x56            ld8 r1=[r33],-8
0xa00000010057f85c class_device_attr_show+0x5c            mov b7=r8

r2 contains the original r33+24, so attr is

kdb> mds %r2-24
0xe000003073917110 1000000001   ........
0xe000003073917118 7270000100000100   ......pr
0xe000003073917120 72742f6574617669   ivate/tr
0xe000003073917128 5a5a5a5a00656361   ace.ZZZZ
0xe000003073917130 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe000003073917138 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe000003073917140 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe000003073917148 a55a5a5a5a5a5a5a   ZZZZZZZ.

This does not match the contents of r33.  class_device_attr_show() is
being passed the address of freed memory which has been reused by the
time of the oops.

dentry->d_fsdata is at e000003472e22640.

kdb> mds e000003472e22640
0xe000003472e22640 00000001   ........					count
0xe000003472e22648 e000003472e22648   H&.r4...				s_sibling
0xe000003472e22650 e000003472e22648   H&.r4...
0xe000003472e22658 e000003472e22658   X&.r4...				s_children
0xe000003472e22660 e000003472e22658   X&.r4...
0xe000003472e22668 e000003073917110   .q.s0...				s_element
0xe000003472e22670 812400000004   ....$...				s_type, s_mode
0xe000003472e22678 e00000301aced2a0   ....0...				s_dentry
0xe000003472e22680 00000000   ........					s_iattr

s_element contains e000003073917110.  This matches the attr passed to
class_device_attr_show, which contains bad data.

BTW, ps shows lots of udev and hotplug related processes.  Race between
bits of udev?

      5 automount
      2 blogd
      1 cupsd
     51 generic_udev.ag
    175 hotplug
      1 init
      1 klogd
    124 logger
      1 master
      1 ntpd
      1 pickup
      1 pidof
      1 pmcd
      1 pmdasample
      1 pmdasimple
      1 pmdaweblog
      1 portmap
      1 postconf
      1 powersaved
      1 qmgr
      1 rc
      1 rpc.mountd
      2 S13kbd
      3 S13postfix
      4 salinfo_decode
      4 salinfo_decode_
      1 sed
     75 sleep
      1 sshd
      2 startpar
      1 syslogd
     24 udev

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Keith Owens]

Another (different) manifestation of use after free in sysfs.  It broke
on module_put(owner) in sysfs_release().  FWIW this ia64 build is
uni-processor, so there is a lot more context switching than normally
occurs on udev.

fill_kobj_path: path = '/class/vc/vcs2'
kobject_hotplug: /sbin/hotplug vc seq=1809 HOME=/ PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=add DEVPATH=/class/vc/vcs2 SUBSYSTEM=vc
kobject vcsa2: registering. parent: vc, set: class_obj
kobject_hotplug
fill_kobj_path: path = '/class/vc/vcsa2'
kobject_hotplug: /sbin/hotplug vc seq=1810 HOME=/ PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=add DEVPATH=/class/vc/vcsa2 SUBSYSTEM=vc
kobject_hotplug
fill_kobj_path: path = '/class/vc/vcs1'
kobject_hotplug: /sbin/hotplug vc seq=1811 HOME=/ PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=remove DEVPATH=/class/vc/vcs1 SUBSYSTEM=vc
kobject vcs1: cleaning up
kobject_hotplug
fill_kobj_path: path = '/class/vc/vcsa1'
kobject_hotplug: /sbin/hotplug vc seq=1812 HOME=/ PATH=/sbin:/bin:/usr/sbin:/usr/bin ACTION=remove DEVPATH=/class/vc/vcsa1 SUBSYSTEM=vc
kobject vcsa1: cleaning up
kobject vcs16: cleaning up
Unable to handle kernel paging request at virtual address 6b6b6b6b6b6b6cf3
udev[24414]: Oops 8821862825984 [1]
Modules linked in: md5 ipv6 usbcore raid0 md_mod nls_iso8859_1 nls_cp437 dm_mod sg st osst

Pid: 24414, CPU 0, comm:                 udev
psr : 00001010081a6018 ifs : 8000000000000308 ip  : [<a00000010025c010>]    Not tainted
ip is at sysfs_release+0xf0/0x1c0
unat: 0000000000000000 pfs : 0000000000000308 rsc : 0000000000000003
rnat: 0000000000000000 bsps: 0000000000000000 pr  : 0000000000158659
ldrs: 0000000000000000 ccv : 0000000000000000 fpsr: 0009804c8270033f
csd : 0000000000000000 ssd : 0000000000000000
b0  : a00000010025bff0 b6  : a00000010000e8c0 b7  : a00000010057ff00
f6  : 1003e6b6b6b6b6b6b6b6b f7  : 0ffe58bbeff7b80000000
f8  : 1003e0000000000000578 f9  : 1003e0000000000000005
f10 : 100019ffffffff803b6e3 f11 : 1003e0000000000000005
r1  : a000000100ddf690 r2  : 0000000000000001 r3  : e00000b078360da0
r8  : 0000000000000000 r9  : a000000100be0a40 r10 : 00000000000000f4
r11 : 0000000000000001 r12 : e00000b078367e30 r13 : e00000b078360000
r14 : 6b6b6b6b6b6b6cf3 r15 : 0000000000000001 r16 : e00000b078360da0
r17 : 0000000000000000 r18 : 00000000054cd124 r19 : a0007fff62138000
r20 : a0007fff8c7a0000 r21 : 0000000000000010 r22 : 0000000000004000
r23 : 6b6b6b6b6b6b6b6b r24 : 0000000000000000 r25 : e00000347bff0758
r26 : 0000000000000090 r27 : e0000030752f0728 r28 : e0000030752f0720
r29 : e0000030752f0738 r30 : 0000000000000000 r31 : 0000000000000001

kdb> r s
 r32: e00000b476b32df0  r33: e00000b472417380  r34: 6b6b6b6b6b6b6b6b 
 r35: a00000010019a060  r36: 0000000000000610  r37: 0000000000000610 
 r38: a00000010025bff0  r39: 0000000000000308 

kdb> bt
Stack traceback for pid 24414
0xe00000b078360000    24414    24400  1    0   R  0xe00000b078360300 *udev
0xa00000010025c010 sysfs_release+0xf0
        args (0xe00000b476b32df0, 0xe00000b472417380, 0x6b6b6b6b6b6b6b6b, 0xa00000010019a060, 0x610)
0xa00000010019a060 __fput+0x3c0
        args (0xe00000301eeae8d0, 0xe00000301eeae8f0, 0xe00000b476b32df0, 0xe00000301eeae8e0, 0xe00000347bc91200)
0xa00000010019a0c0 fput+0x40
        args (0xe00000301eeae8d0, 0xa000000100191d60, 0x308, 0xe00000b476b32df0)
0xa000000100191d60 filp_close+0xc0
        args (0xe00000301eeae8d0, 0xe00000b4720d5230, 0x0, 0xa0000001001920d0, 0x919)
0xa0000001001920d0 sys_close+0x2f0
        args (0x6, 0x6000000000058210, 0x4000, 0x280, 0x0)
0xa00000010000b520 ia64_ret_from_syscall
        args (0x6, 0x6000000000058210, 0x4000)
0xa000000000010640 __kernel_syscall_via_break
        args (0x6, 0x6000000000058210, 0x4000)

kdb> inode 0xe00000b476b32df0
struct inode at  0xe00000b476b32df0
 i_ino = 34192 i_count = 1 i_size 16384
 i_mode = 0100444  i_nlink = 0  i_rdev = 0x0
 i_hash.nxt = 0x0000000000000000 i_hash.pprev = 0x0000000000000000
 i_list.nxt = 0xe00000b472084d40 i_list.prv = 0xe00000b476b31c98
 i_dentry.nxt = 0xe00000301d1712a0 i_dentry.prv = 0xe00000301d1712a0
 i_sb = 0xe000003003e5ad58 i_op = 0xa000000100a61488 i_data = 0xe00000b476b32f98 nrpages = 0
 i_fop= 0xa000000100a615c8 i_flock = 0x0000000000000000 i_mapping = 0xe00000b476b32f98
 i_flags 0x0 i_state 0x0 []  fs specific info @ 0xe00000b476b33148

kdb> dentry 0xe00000301d1712a0
Dentry at 0xe00000301d1712a0
 d_name.len = 3 d_name.name = 0xe00000301d171384 <dev>
 d_count = 1 d_flags = 0x18 d_inode = 0xe00000b476b32df0
 d_parent = 0xe00000301d171a80
 d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000200200
 d_lru.nxt = 0xe00000301d1712f8 d_lru.prv = 0xe00000301d1712f8
 d_child.nxt = 0xe00000301d171af8 d_child.prv = 0xe00000301d171af8
 d_subdirs.nxt = 0xe00000301d171318 d_subdirs.prv = 0xe00000301d171318
 d_alias.nxt = 0xe00000b476b32e20 d_alias.prv = 0xe00000b476b32e20
 d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Andrew Morton]

Keith Owens <kaos@sgi.com> wrote:
>
> On Sat, 30 Jul 2005 02:29:55 -0700,
> Andrew Morton <akpm@osdl.org> wrote:
> >Keith Owens <kaos@sgi.com> wrote:
> >>
> >> 2.6.13-rc4 + kdb, with lots of CONFIG_DEBUG options.  There is an
> >>  intermittent use after free in class_device_attr_show.  Reboot with no
> >>  changes and the problem does not always recur.
> >> ...
> >>  ip is at class_device_attr_show+0x50/0xa0
> >> ...
> >
> >It might help to know which file is being read from here.
> >
> >The below patch will record the name of the most-recently-opened sysfs
> >file.  You can print last_sysfs_file[] in the debugger or add the
> >appropriate printk to the ia64 code?
> 
> No need for a patch.  It is /dev/vcsa2.

You mean /sys/class/vc/vcsa2?

That appears to be using generic code...

Can you please summarise what you curently know about this bug?  What is
being accessed after free in class_device_attr_show()?  class_dev_attr? 
cd?

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Keith Owens]

On Mon, 1 Aug 2005 12:03:21 -0700,
Andrew Morton <akpm@osdl.org> wrote:
>Keith Owens <kaos@sgi.com> wrote:
>>
>> On Sat, 30 Jul 2005 02:29:55 -0700,
>> Andrew Morton <akpm@osdl.org> wrote:
>> >Keith Owens <kaos@sgi.com> wrote:
>> >>
>> >> 2.6.13-rc4 + kdb, with lots of CONFIG_DEBUG options.  There is an
>> >>  intermittent use after free in class_device_attr_show.  Reboot with no
>> >>  changes and the problem does not always recur.
>> >> ...
>> >>  ip is at class_device_attr_show+0x50/0xa0
>> >> ...
>> >
>> >It might help to know which file is being read from here.
>> >
>> >The below patch will record the name of the most-recently-opened sysfs
>> >file.  You can print last_sysfs_file[] in the debugger or add the
>> >appropriate printk to the ia64 code?
>>
>> No need for a patch.  It is /dev/vcsa2.
>
>You mean /sys/class/vc/vcsa2?

The vcsnn value varies.  I traced the dentry parent chain for the
latest event.  From bottom to top the d_name entries are

  dev, vcs16, vc, class, /.

That makes no sense, why is dev a child of vcs16?  Raw data at the end.

>That appears to be using generic code...
>
>Can you please summarise what you curently know about this bug?  What is
>being accessed after free in class_device_attr_show()?  class_dev_attr?
>cd?

IA64, compiled for both SMP and uni-processor.  Lots of debug configs,
including slab poisoning.

The problem was first noticed at 2.6.13-rc3, it has also been seen in
-rc4.  It is very intermittent, so -rc3 may not be the starting point.

Failures have been seen in two sysfs routines,
sysfs_read_file()->class_device_attr_show() and
sysfs_release()->module_put(owner).

The common denominator in the failures is that sd->s_element points to
poisoned data.

Raw data, from the failure in sysfs_release:

kdb> filp 0xe00000301eeae8d0
name.name 0xe00000301d171384  name.len  3
File Pointer at 0xe00000301eeae8d0
 f_list.nxt = 0xe00000301eeaea08 f_list.prv = 0xe000003003e5aeb8
 f_dentry = 0xe00000301d1712a0 f_op = 0xa000000100a615c8
 f_count = 0 f_flags = 0x8000 f_mode = 0xd
 f_pos = 5

dentry parent chain.  /class/vc/vcs16/dev WTF?

kdb> dentry 0xe00000301d1712a0
Dentry at 0xe00000301d1712a0
 d_name.len = 3 d_name.name = 0xe00000301d171384 <dev>
 d_count = 1 d_flags = 0x18 d_inode = 0xe00000b476b32df0
 d_parent = 0xe00000301d171a80
 d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000200200
 d_lru.nxt = 0xe00000301d1712f8 d_lru.prv = 0xe00000301d1712f8
 d_child.nxt = 0xe00000301d171af8 d_child.prv = 0xe00000301d171af8
 d_subdirs.nxt = 0xe00000301d171318 d_subdirs.prv = 0xe00000301d171318
 d_alias.nxt = 0xe00000b476b32e20 d_alias.prv = 0xe00000b476b32e20
 d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58

kdb> dentry 0xe00000301d171a80
Dentry at 0xe00000301d171a80
 d_name.len = 5 d_name.name = 0xe00000301d171b64 <vcs16>
 d_count = 2 d_flags = 0x10 d_inode = 0xe00000301986cac0
 d_parent = 0xe00000347b87c880
 d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000200200
 d_lru.nxt = 0xe00000301d171ad8 d_lru.prv = 0xe00000301d171ad8
 d_child.nxt = 0xe000003011ba9ae8 d_child.prv = 0xe000003019f974c8
 d_subdirs.nxt = 0xe00000301d171308 d_subdirs.prv = 0xe00000301d171308
 d_alias.nxt = 0xe00000301986caf0 d_alias.prv = 0xe00000301986caf0
 d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58

kdb> dentry 0xe00000347b87c880
Dentry at 0xe00000347b87c880
 d_name.len = 2 d_name.name = 0xe00000347b87c964 <vc>
 d_count = 8 d_flags = 0x0 d_inode = 0xe00000b47a5dad70
 d_parent = 0xe00000b47a404760
 d_hash.nxt = 0x0000000000000000 d_hash.prv = 0xa00000020079d000
 d_lru.nxt = 0xe00000347b87c8d8 d_lru.prv = 0xe00000347b87c8d8
 d_child.nxt = 0xe00000b47a445668 d_child.prv = 0xe00000347b921548
 d_subdirs.nxt = 0xe00000301a1fd788 d_subdirs.prv = 0xe00000347b87c7c8
 d_alias.nxt = 0xe00000b47a5dada0 d_alias.prv = 0xe00000b47a5dada0
 d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58

kdb> dentry 0xe00000b47a404760
Dentry at 0xe00000b47a404760
 d_name.len = 5 d_name.name = 0xe00000b47a404844 <class>
 d_count = 20 d_flags = 0x0 d_inode = 0xe00000347bc95c18
 d_parent = 0xe00000b47a405180
 d_hash.nxt = 0x0000000000000000 d_hash.prv = 0xa0000002002d4bc8
 d_lru.nxt = 0xe00000b47a4047b8 d_lru.prv = 0xe00000b47a4047b8
 d_child.nxt = 0xe00000b47a4048e8 d_child.prv = 0xe00000b47a4046a8
 d_subdirs.nxt = 0xe000003013818d68 d_subdirs.prv = 0xe00000b47a405d28
 d_alias.nxt = 0xe00000347bc95c48 d_alias.prv = 0xe00000347bc95c48
 d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58

kdb> dentry 0xe00000b47a405180
Dentry at 0xe00000b47a405180
 d_name.len = 1 d_name.name = 0xe00000b47a405264 </>
 d_count = 11 d_flags = 0x10 d_inode = 0xe00000347bc97460
 d_parent = 0xe00000b47a405180
 d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000000000
 d_lru.nxt = 0xe00000b47a4051d8 d_lru.prv = 0xe00000b47a4051d8
 d_child.nxt = 0xe00000b47a4051e8 d_child.prv = 0xe00000b47a4051e8
 d_subdirs.nxt = 0xe00000b47a446ce8 d_subdirs.prv = 0xe00000b47a404a08
 d_alias.nxt = 0xe00000347bc97490 d_alias.prv = 0xe00000347bc97490
 d_op = 0x0000000000000000 d_sb = 0xe000003003e5ad58

Hex dump of dentry passed via filp to sysfs_release.

kdb> mds 0xe00000301d1712a0
0xe00000301d1712a0 1800000001   ........
0xe00000301d1712a8 1d244b3c   <K$.....
0xe00000301d1712b0 00000000   ........
0xe00000301d1712b8 5a5a5a5a00000005   ....ZZZZ
0xe00000301d1712c0 a00000010092c618 __func__.4+0xeaf8
0xe00000301d1712c8 a00000010092caf8 __func__.4+0xefd8
0xe00000301d1712d0 5a5a5a5a00000215   ....ZZZZ
0xe00000301d1712d8 e00000b476b32df0   .-.v....
0xe00000301d1712e0 e00000301d171a80   ....0...
0xe00000301d1712e8 30023ee05   ..#.....
0xe00000301d1712f0 e00000301d171384   ....0...
0xe00000301d1712f8 e00000301d1712f8   ....0...
0xe00000301d171300 e00000301d1712f8   ....0...
0xe00000301d171308 e00000301d171af8   ....0...
0xe00000301d171310 e00000301d171af8   ....0...
0xe00000301d171318 e00000301d171318   ....0...
0xe00000301d171320 e00000301d171318   ....0...
0xe00000301d171328 e00000b476b32e20    ..v....
0xe00000301d171330 e00000b476b32e20    ..v....
0xe00000301d171338 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe00000301d171340 a000000100a61870 sysfs_dentry_ops
0xe00000301d171348 e000003003e5ad58   X...0...			d_sb
0xe00000301d171350 e0000030701f6d00   .m.p0...			d_fsdata
0xe00000301d171358 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe00000301d171360 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe00000301d171368 00000000   ........
0xe00000301d171370 00000000   ........
0xe00000301d171378 00200200   .. .....
0xe00000301d171380 76656400000000   ....dev.
0xe00000301d171388 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe00000301d171390 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe00000301d171398 5a5a5a5a5a5a5a5a   ZZZZZZZZ
0xe00000301d1713a0 a55a5a5a5a5a5a5a   ZZZZZZZ.

kdb> sb e000003003e5ad58
struct super_block at  0xe000003003e5ad58
 s_dev 0x0 blocksize 0x4000
 s_flags 0x40000000 s_root 0xe00000b47a405180
 s_dirt 0 s_dirty.next 0xe000003003e5ae90 s_dirty.prev 0xe000003003e5ae90
 s_frozen 0 s_id [sysfs]

fsdata (sysfs_dirent).

kdb> mds e0000030701f6d00
0xe0000030701f6d00 00000001   ........		s_count
0xe0000030701f6d08 e0000030701f6d08   .m.p0...	s_sibling
0xe0000030701f6d10 e0000030701f6d08   .m.p0...
0xe0000030701f6d18 e0000030701f6d18   .m.p0...	s_children
0xe0000030701f6d20 e0000030701f6d18   .m.p0...
0xe0000030701f6d28 e000003073607c10   .|`s0...	s_element
0xe0000030701f6d30 812400000004   ....$...	s_type, s_mode
0xe0000030701f6d38 e00000301d1712a0   ....0...	s_dentry
0xe0000030701f6d40 00000000   ........		s_iattr

s_element

kdb> mds e000003073607c10
0xe000003073607c10 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003073607c18 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003073607c20 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003073607c28 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003073607c30 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003073607c38 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003073607c40 6b6b6b6b6b6b6b6b   kkkkkkkk
0xe000003073607c48 a56b6b6b6b6b6b6b   kkkkkkk.

The failure was caused by the bad data referenced by s_element.

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Keith Owens]

On Tue, 02 Aug 2005 13:05:50 +1000, 
Keith Owens <kaos@sgi.com> wrote:
>The vcsnn value varies.  I traced the dentry parent chain for the
>latest event.  From bottom to top the d_name entries are
>
>  dev, vcs16, vc, class, /.
>
>That makes no sense, why is dev a child of vcs16?  Raw data at the end.

Ignore that bit, I was confusing /dev and dev as a subdir of a sysfs
entry.  The parent chain is right.

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Maneesh Soni]

On Tue, Aug 02, 2005 at 01:05:50PM +1000, Keith Owens wrote:
> On Mon, 1 Aug 2005 12:03:21 -0700,
> Andrew Morton <akpm@osdl.org> wrote:
> >Keith Owens <kaos@sgi.com> wrote:
> >>
> >> On Sat, 30 Jul 2005 02:29:55 -0700,
> >> Andrew Morton <akpm@osdl.org> wrote:
> >> >Keith Owens <kaos@sgi.com> wrote:
> >> >>
> >> >> 2.6.13-rc4 + kdb, with lots of CONFIG_DEBUG options.  There is an
> >> >>  intermittent use after free in class_device_attr_show.  Reboot with no
> >> >>  changes and the problem does not always recur.
> >> >> ...
> >> >>  ip is at class_device_attr_show+0x50/0xa0
> >> >> ...
> >> >
> >> >It might help to know which file is being read from here.
> >> >
> >> >The below patch will record the name of the most-recently-opened sysfs
> >> >file.  You can print last_sysfs_file[] in the debugger or add the
> >> >appropriate printk to the ia64 code?
> >>
> >> No need for a patch.  It is /dev/vcsa2.
> >
> >You mean /sys/class/vc/vcsa2?
> 
> The vcsnn value varies.  I traced the dentry parent chain for the
> latest event.  From bottom to top the d_name entries are
> 
>   dev, vcs16, vc, class, /.
> 
> That makes no sense, why is dev a child of vcs16?  Raw data at the end.
> 

The path looks ok..

[root@llm01 ~]# ls -l /sys/class/vc/vcs1/dev
-r--r--r--  1 root root 4096 Aug  1 19:35 /sys/class/vc/vcs1/dev
[root@llm01 ~]# cat /sys/class/vc/vcs1/dev
7:1

> >That appears to be using generic code...
> >
> >Can you please summarise what you curently know about this bug?  What is
> >being accessed after free in class_device_attr_show()?  class_dev_attr?
> >cd?
> 
> IA64, compiled for both SMP and uni-processor.  Lots of debug configs,
> including slab poisoning.
> 
> The problem was first noticed at 2.6.13-rc3, it has also been seen in
> -rc4.  It is very intermittent, so -rc3 may not be the starting point.
> 
> Failures have been seen in two sysfs routines,
> sysfs_read_file()->class_device_attr_show() and
> sysfs_release()->module_put(owner).
> 
> The common denominator in the failures is that sd->s_element points to
> poisoned data.
> 
> Raw data, from the failure in sysfs_release:
> 
> kdb> filp 0xe00000301eeae8d0
> name.name 0xe00000301d171384  name.len  3
> File Pointer at 0xe00000301eeae8d0
>  f_list.nxt = 0xe00000301eeaea08 f_list.prv = 0xe000003003e5aeb8
>  f_dentry = 0xe00000301d1712a0 f_op = 0xa000000100a615c8
>  f_count = 0 f_flags = 0x8000 f_mode = 0xd
>  f_pos = 5
> 
> dentry parent chain.  /class/vc/vcs16/dev WTF?
> 
> kdb> dentry 0xe00000301d1712a0
> Dentry at 0xe00000301d1712a0
>  d_name.len = 3 d_name.name = 0xe00000301d171384 <dev>
>  d_count = 1 d_flags = 0x18 d_inode = 0xe00000b476b32df0
>  d_parent = 0xe00000301d171a80
>  d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000200200
>  d_lru.nxt = 0xe00000301d1712f8 d_lru.prv = 0xe00000301d1712f8
>  d_child.nxt = 0xe00000301d171af8 d_child.prv = 0xe00000301d171af8
>  d_subdirs.nxt = 0xe00000301d171318 d_subdirs.prv = 0xe00000301d171318
>  d_alias.nxt = 0xe00000b476b32e20 d_alias.prv = 0xe00000b476b32e20
>  d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58
> 
> kdb> dentry 0xe00000301d171a80
> Dentry at 0xe00000301d171a80
>  d_name.len = 5 d_name.name = 0xe00000301d171b64 <vcs16>
>  d_count = 2 d_flags = 0x10 d_inode = 0xe00000301986cac0
>  d_parent = 0xe00000347b87c880
>  d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000200200
>  d_lru.nxt = 0xe00000301d171ad8 d_lru.prv = 0xe00000301d171ad8
>  d_child.nxt = 0xe000003011ba9ae8 d_child.prv = 0xe000003019f974c8
>  d_subdirs.nxt = 0xe00000301d171308 d_subdirs.prv = 0xe00000301d171308
>  d_alias.nxt = 0xe00000301986caf0 d_alias.prv = 0xe00000301986caf0
>  d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58
> 
> kdb> dentry 0xe00000347b87c880
> Dentry at 0xe00000347b87c880
>  d_name.len = 2 d_name.name = 0xe00000347b87c964 <vc>
>  d_count = 8 d_flags = 0x0 d_inode = 0xe00000b47a5dad70
>  d_parent = 0xe00000b47a404760
>  d_hash.nxt = 0x0000000000000000 d_hash.prv = 0xa00000020079d000
>  d_lru.nxt = 0xe00000347b87c8d8 d_lru.prv = 0xe00000347b87c8d8
>  d_child.nxt = 0xe00000b47a445668 d_child.prv = 0xe00000347b921548
>  d_subdirs.nxt = 0xe00000301a1fd788 d_subdirs.prv = 0xe00000347b87c7c8
>  d_alias.nxt = 0xe00000b47a5dada0 d_alias.prv = 0xe00000b47a5dada0
>  d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58
> 
> kdb> dentry 0xe00000b47a404760
> Dentry at 0xe00000b47a404760
>  d_name.len = 5 d_name.name = 0xe00000b47a404844 <class>
>  d_count = 20 d_flags = 0x0 d_inode = 0xe00000347bc95c18
>  d_parent = 0xe00000b47a405180
>  d_hash.nxt = 0x0000000000000000 d_hash.prv = 0xa0000002002d4bc8
>  d_lru.nxt = 0xe00000b47a4047b8 d_lru.prv = 0xe00000b47a4047b8
>  d_child.nxt = 0xe00000b47a4048e8 d_child.prv = 0xe00000b47a4046a8
>  d_subdirs.nxt = 0xe000003013818d68 d_subdirs.prv = 0xe00000b47a405d28
>  d_alias.nxt = 0xe00000347bc95c48 d_alias.prv = 0xe00000347bc95c48
>  d_op = 0xa000000100a61870 d_sb = 0xe000003003e5ad58
> 
> kdb> dentry 0xe00000b47a405180
> Dentry at 0xe00000b47a405180
>  d_name.len = 1 d_name.name = 0xe00000b47a405264 </>
>  d_count = 11 d_flags = 0x10 d_inode = 0xe00000347bc97460
>  d_parent = 0xe00000b47a405180
>  d_hash.nxt = 0x0000000000000000 d_hash.prv = 0x0000000000000000
>  d_lru.nxt = 0xe00000b47a4051d8 d_lru.prv = 0xe00000b47a4051d8
>  d_child.nxt = 0xe00000b47a4051e8 d_child.prv = 0xe00000b47a4051e8
>  d_subdirs.nxt = 0xe00000b47a446ce8 d_subdirs.prv = 0xe00000b47a404a08
>  d_alias.nxt = 0xe00000347bc97490 d_alias.prv = 0xe00000347bc97490
>  d_op = 0x0000000000000000 d_sb = 0xe000003003e5ad58
> 
> Hex dump of dentry passed via filp to sysfs_release.
> 
> kdb> mds 0xe00000301d1712a0
> 0xe00000301d1712a0 1800000001   ........
> 0xe00000301d1712a8 1d244b3c   <K$.....
> 0xe00000301d1712b0 00000000   ........
> 0xe00000301d1712b8 5a5a5a5a00000005   ....ZZZZ
> 0xe00000301d1712c0 a00000010092c618 __func__.4+0xeaf8
> 0xe00000301d1712c8 a00000010092caf8 __func__.4+0xefd8
> 0xe00000301d1712d0 5a5a5a5a00000215   ....ZZZZ
> 0xe00000301d1712d8 e00000b476b32df0   .-.v....
> 0xe00000301d1712e0 e00000301d171a80   ....0...
> 0xe00000301d1712e8 30023ee05   ..#.....
> 0xe00000301d1712f0 e00000301d171384   ....0...
> 0xe00000301d1712f8 e00000301d1712f8   ....0...
> 0xe00000301d171300 e00000301d1712f8   ....0...
> 0xe00000301d171308 e00000301d171af8   ....0...
> 0xe00000301d171310 e00000301d171af8   ....0...
> 0xe00000301d171318 e00000301d171318   ....0...
> 0xe00000301d171320 e00000301d171318   ....0...
> 0xe00000301d171328 e00000b476b32e20    ..v....
> 0xe00000301d171330 e00000b476b32e20    ..v....
> 0xe00000301d171338 5a5a5a5a5a5a5a5a   ZZZZZZZZ
> 0xe00000301d171340 a000000100a61870 sysfs_dentry_ops
> 0xe00000301d171348 e000003003e5ad58   X...0...			d_sb
> 0xe00000301d171350 e0000030701f6d00   .m.p0...			d_fsdata
> 0xe00000301d171358 5a5a5a5a5a5a5a5a   ZZZZZZZZ
> 0xe00000301d171360 5a5a5a5a5a5a5a5a   ZZZZZZZZ
> 0xe00000301d171368 00000000   ........
> 0xe00000301d171370 00000000   ........
> 0xe00000301d171378 00200200   .. .....
> 0xe00000301d171380 76656400000000   ....dev.
> 0xe00000301d171388 5a5a5a5a5a5a5a5a   ZZZZZZZZ
> 0xe00000301d171390 5a5a5a5a5a5a5a5a   ZZZZZZZZ
> 0xe00000301d171398 5a5a5a5a5a5a5a5a   ZZZZZZZZ
> 0xe00000301d1713a0 a55a5a5a5a5a5a5a   ZZZZZZZ.
> 
> kdb> sb e000003003e5ad58
> struct super_block at  0xe000003003e5ad58
>  s_dev 0x0 blocksize 0x4000
>  s_flags 0x40000000 s_root 0xe00000b47a405180
>  s_dirt 0 s_dirty.next 0xe000003003e5ae90 s_dirty.prev 0xe000003003e5ae90
>  s_frozen 0 s_id [sysfs]
> 
> fsdata (sysfs_dirent).
> 
> kdb> mds e0000030701f6d00
> 0xe0000030701f6d00 00000001   ........		s_count
> 0xe0000030701f6d08 e0000030701f6d08   .m.p0...	s_sibling
> 0xe0000030701f6d10 e0000030701f6d08   .m.p0...
> 0xe0000030701f6d18 e0000030701f6d18   .m.p0...	s_children
> 0xe0000030701f6d20 e0000030701f6d18   .m.p0...
> 0xe0000030701f6d28 e000003073607c10   .|`s0...	s_element
> 0xe0000030701f6d30 812400000004   ....$...	s_type, s_mode
> 0xe0000030701f6d38 e00000301d1712a0   ....0...	s_dentry
> 0xe0000030701f6d40 00000000   ........		s_iattr
> 
> s_element
> 
> kdb> mds e000003073607c10
> 0xe000003073607c10 6b6b6b6b6b6b6b6b   kkkkkkkk
> 0xe000003073607c18 6b6b6b6b6b6b6b6b   kkkkkkkk
> 0xe000003073607c20 6b6b6b6b6b6b6b6b   kkkkkkkk
> 0xe000003073607c28 6b6b6b6b6b6b6b6b   kkkkkkkk
> 0xe000003073607c30 6b6b6b6b6b6b6b6b   kkkkkkkk
> 0xe000003073607c38 6b6b6b6b6b6b6b6b   kkkkkkkk
> 0xe000003073607c40 6b6b6b6b6b6b6b6b   kkkkkkkk
> 0xe000003073607c48 a56b6b6b6b6b6b6b   kkkkkkk.
> 
> The failure was caused by the bad data referenced by s_element.
> 

Looks like the attribute structure is allocated dynamically and
is freed before the sysfs_release() is called?

Basically it could be like this..

file (/sys/class/vc/vcs16/dev) is still open and the corresponding
attribute structure is already gone. open files will the keep the
corresponding dentry and in-turn sysfs_dirent alive.

sysfs_open_file() does call kobject_get() and it expects the
kobject to be around while the sysfs files for kobject's corresponding
attributes are open.

Greg, could there be cases where the kobject is alive but
attributes are freed? In those cases we will need some
way to keep attrbiutes alive while kobject is around.

Thanks
Maneesh

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Greg KH]

On Tue, Aug 02, 2005 at 01:34:22PM +0530, Maneesh Soni wrote:
> Looks like the attribute structure is allocated dynamically and
> is freed before the sysfs_release() is called?
> 
> Basically it could be like this..
> 
> file (/sys/class/vc/vcs16/dev) is still open and the corresponding
> attribute structure is already gone. open files will the keep the
> corresponding dentry and in-turn sysfs_dirent alive.
> 
> sysfs_open_file() does call kobject_get() and it expects the
> kobject to be around while the sysfs files for kobject's corresponding
> attributes are open.
> 
> Greg, could there be cases where the kobject is alive but
> attributes are freed? In those cases we will need some
> way to keep attrbiutes alive while kobject is around.

Well, we need to remove the attributes before we free the kobject,
right?  It looks like we are racing here, I'll dig into this and see if
I can find anything...

thanks,

greg k-h

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Keith Owens]

FYI, the intermittent free after use in sysfs is still there in
2.6.13-rc6.

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Maneesh Soni]

On Wed, Aug 10, 2005 at 04:26:51PM +1000, Keith Owens wrote:
> FYI, the intermittent free after use in sysfs is still there in
> 2.6.13-rc6.
> 

The race condition is known here. It is some thing in the upper layer. 
In this case "driver/base/class.c" which frees the kobject's attributes 
even if there are live references to kobject.


open sysfs file				unregister class device
sysfs_open_file()			class_device_del()
  -> takes a ref on kobject		  -> kfree attribute struct
     -> accesses attributes		  -> kobject_del()
					      -> kref_put()	
close sysfs file				  
sysfs_release()				    
  -> acesses attributes using s_element
  -> drops ref to kobject

Solution could be either we have reference counting for attributes also
or keep attributes alive till the last reference to the kobject. Both these
needs changes in the driver core.

Greg, will the following patch make sense? This postpones the kfree() of
devt_attr till class_dev_release() is called. 

Please check this patch out, if this helps or not.

Thanks
Maneesh


o following patch moves the code to free devt_attr from class_device_del()
  to class_dev_release() which is called after the last reference to the
  corresponding kobject() is gone. This allows to keep the devt_attr 
  alive while the corresponding sysfs file is open.

Signed-off-by: Maneesh Soni <maneesh@in.ibm.com>
---

 linux-2.6.13-rc6-maneesh/drivers/base/class.c |   14 +++++++++-----
 1 files changed, 9 insertions(+), 5 deletions(-)

diff -puN drivers/base/class.c~fix-class-attributes-race drivers/base/class.c
--- linux-2.6.13-rc6/drivers/base/class.c~fix-class-attributes-race	2005-08-10 12:35:06.154386456 +0530
+++ linux-2.6.13-rc6-maneesh/drivers/base/class.c	2005-08-10 14:27:12.903765112 +0530
@@ -299,6 +299,11 @@ static void class_dev_release(struct kob
 
 	pr_debug("device class '%s': release.\n", cd->class_id);
 
+        if (cd->devt_attr) {
+                kfree(cd->devt_attr);
+                cd->devt_attr = NULL;
+        }
+
 	if (cls->release)
 		cls->release(cd);
 	else {
@@ -591,11 +596,10 @@ void class_device_del(struct class_devic
 
 	if (class_dev->dev)
 		sysfs_remove_link(&class_dev->kobj, "device");
-	if (class_dev->devt_attr) {
-		class_device_remove_file(class_dev, class_dev->devt_attr);
-		kfree(class_dev->devt_attr);
-		class_dev->devt_attr = NULL;
-	}
+
+	if (class_dev->devt_attr)
+                class_device_remove_file(cd, cd->devt_attr);
+
 	class_device_remove_attrs(class_dev);
 
 	kobject_hotplug(&class_dev->kobj, KOBJ_REMOVE);
_

-- 
Maneesh Soni
Linux Technology Center, 
IBM India Software Labs,
Bangalore, India
email: maneesh@in.ibm.com
Phone: 91-80-25044990

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Greg KH]

On Wed, Aug 10, 2005 at 03:36:36PM +0530, Maneesh Soni wrote:
> On Wed, Aug 10, 2005 at 04:26:51PM +1000, Keith Owens wrote:
> > FYI, the intermittent free after use in sysfs is still there in
> > 2.6.13-rc6.
> > 
> 
> The race condition is known here. It is some thing in the upper layer. 
> In this case "driver/base/class.c" which frees the kobject's attributes 
> even if there are live references to kobject.
> 
> 
> open sysfs file				unregister class device
> sysfs_open_file()			class_device_del()
>   -> takes a ref on kobject		  -> kfree attribute struct
>      -> accesses attributes		  -> kobject_del()
> 					      -> kref_put()	
> close sysfs file				  
> sysfs_release()				    
>   -> acesses attributes using s_element
>   -> drops ref to kobject
> 
> Solution could be either we have reference counting for attributes also
> or keep attributes alive till the last reference to the kobject. Both these
> needs changes in the driver core.
> 
> Greg, will the following patch make sense? This postpones the kfree() of
> devt_attr till class_dev_release() is called. 

Yes, that patch looks good, if you fix up the space vs. tabs issue :)

But will that really fix this race?  I was under the impression the oops
didn't come from trying to access the devt_attr, but the sysfs s_element
pointer?

> Please check this patch out, if this helps or not.

I'd be interested in seeing if this fixes it.

thanks,

greg k-h

Re: 2.6.13-rc4 use after free in class_device_attr_show

[Maneesh Soni]

On Wed, Aug 10, 2005 at 03:35:53PM -0700, Greg KH wrote:
> On Wed, Aug 10, 2005 at 03:36:36PM +0530, Maneesh Soni wrote:
> > On Wed, Aug 10, 2005 at 04:26:51PM +1000, Keith Owens wrote:
> > > FYI, the intermittent free after use in sysfs is still there in
> > > 2.6.13-rc6.
> > > 
> > 
> > The race condition is known here. It is some thing in the upper layer. 
> > In this case "driver/base/class.c" which frees the kobject's attributes 
> > even if there are live references to kobject.
> > 
> > 
> > open sysfs file				unregister class device
> > sysfs_open_file()			class_device_del()
> >   -> takes a ref on kobject		  -> kfree attribute struct
> >      -> accesses attributes		  -> kobject_del()
> > 					      -> kref_put()	
> > close sysfs file				  
> > sysfs_release()				    
> >   -> acesses attributes using s_element
> >   -> drops ref to kobject
> > 
> > Solution could be either we have reference counting for attributes also
> > or keep attributes alive till the last reference to the kobject. Both these
> > needs changes in the driver core.
> > 
> > Greg, will the following patch make sense? This postpones the kfree() of
> > devt_attr till class_dev_release() is called. 
> 
> Yes, that patch looks good, if you fix up the space vs. tabs issue :)
> 

yuk.. sorry for that.. I corrected that now.

> But will that really fix this race?  I was under the impression the oops
> didn't come from trying to access the devt_attr, but the sysfs s_element
> pointer?

I am not able to recreate the race with or without the patch though. As per
the stack traces, and the debug messages from antother thread also,
I could see that it is use after free for attribute structure. s_element
is a pointer to the attribute structure in case of sysfs "files". Most of
the times this attribute structure is not allocated/freed dynamically unlike
/sys/class/vc/vcs*/dev, so we don't see any crashes.


> > Please check this patch out, if this helps or not.
> 
> I'd be interested in seeing if this fixes it.
> 

I just cc-ed others also who reported similar oops.

Thanks
Maneesh




o following patch moves the code to free devt_attr from class_device_del()
  to class_dev_release() which is called after the last reference to the
  corresponding kobject() is gone. This allows to keep the devt_attr 
  alive while the corresponding sysfs file is open.

Signed-off-by: Maneesh Soni <maneesh@in.ibm.com>
---

 linux-2.6.13-rc6-maneesh/drivers/base/class.c |   14 +++++++++-----
 1 files changed, 9 insertions(+), 5 deletions(-)

diff -puN drivers/base/class.c~fix-class-attributes-race drivers/base/class.c
--- linux-2.6.13-rc6/drivers/base/class.c~fix-class-attributes-race	2005-08-10 12:35:06.000000000 +0530
+++ linux-2.6.13-rc6-maneesh/drivers/base/class.c	2005-08-11 09:27:17.202081088 +0530
@@ -299,6 +299,11 @@ static void class_dev_release(struct kob
 
 	pr_debug("device class '%s': release.\n", cd->class_id);
 
+	if (cd->devt_attr) {
+		kfree(cd->devt_attr);
+		cd->devt_attr = NULL;
+	}
+
 	if (cls->release)
 		cls->release(cd);
 	else {
@@ -591,11 +596,10 @@ void class_device_del(struct class_devic
 
 	if (class_dev->dev)
 		sysfs_remove_link(&class_dev->kobj, "device");
-	if (class_dev->devt_attr) {
-		class_device_remove_file(class_dev, class_dev->devt_attr);
-		kfree(class_dev->devt_attr);
-		class_dev->devt_attr = NULL;
-	}
+
+	if (class_dev->devt_attr)
+                class_device_remove_file(class_dev, class_dev->devt_attr);
+
 	class_device_remove_attrs(class_dev);
 
 	kobject_hotplug(&class_dev->kobj, KOBJ_REMOVE);
_

-- 
Maneesh Soni
Linux Technology Center, 
IBM India Software Labs,
Bangalore, India
email: maneesh@in.ibm.com
Phone: 91-80-25044990