zynq | CCF | SRCU

Hi,

we recently encountered some kernel panics when we compiled one of our drivers as module and tested inserting/removing the module. Trying to debug this issue, I could reproduce it on the mainline kernel with a dummy module.

What happens is, that when on driver remove clk_notifier_unregister() is called and no other notifier for that clock is registered, the kernel panics.
I'm not sure what is going wrong here. If there is a bug (and if where) or I'm just using the infrastructure the wrong way,... So, any hint is appreciated.

I attach the output from the crashing system. The stacktrace indicates a crash in 'srcu_readers_seq_idx()'.
I also attach the module I used to trigger the issue and a patch on top of mainline commit a93cb29acaa8f75618c3f202d1cf43c231984644 which has the DT modifications I need to make the module find its clock and boot with my initramfs.

	Thanks,
	S??ren

-------------- next part --------------

U-Boot 2013.01-00001-g7926df4 (Apr 09 2013 - 09:45:48)

I2C:   ready
DRAM:  1 GiB
WARNING: Caches not enabled
MMC:   zynq_sdhci: 0
SF: Detected N25Q128A with page size 64 KiB, total 16 MiB

*** Warning - bad CRC, using default environment

In:    serial
Out:   serial
Err:   serial
Net:   Gem.e000b000
Hit any key to stop autoboot:  3  2  1  0 

TFTPing Linux to RAM...
Gem.e000b000 Waiting for PHY auto negotiation to complete..... done Using Gem.e000b000 device
TFTP from server 10.10.70.101; our IP address is 10.10.70.102 Filename 'uImage'.
Load address: 0x3000000
Loading: *T #################################################################

	 #################################################################
	 ##################################
	 410.2 KiB/s

done
Bytes transferred = 2397912 (2496d8 hex)
Gem.e000b000:7 is connected to Gem.e000b000. Reconnecting to Gem.e000b000 Gem.e000b000 Waiting for PHY auto negotiation to complete..... done Using Gem.e000b000 device
TFTP from server 10.10.70.101; our IP address is 10.10.70.102 Filename 'devicetree.dtb'.
Load address: 0x2a00000
Loading: *#

	 200.2 KiB/s

done
Bytes transferred = 3078 (c06 hex)
Gem.e000b000:7 is connected to Gem.e000b000. Reconnecting to Gem.e000b000 Gem.e000b000 Waiting for PHY auto negotiation to complete..... done Using Gem.e000b000 device
TFTP from server 10.10.70.101; our IP address is 10.10.70.102 Filename 'uramdisk.image.gz'.
Load address: 0x2000000
Loading: *#################################################################

	 #################################################################
	 #################################################################
	 ################################################################
	 3.4 MiB/s
done
Bytes transferred = 3792138 (39dd0a hex)
## Booting kernel from Legacy Image at 03000000 ...
   Image Name:   Linux-3.10.0-rc3-00119-ga93cb29-
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    2397848 Bytes = 2.3 MiB

Load Address: 00008000
Entry Point: 00008000
Verifying Checksum ... OK
## Loading init Ramdisk from Legacy Image at 02000000 ...
Image Name:
Image Type: ARM Linux RAMDisk Image (gzip compressed)
Data Size: 3792074 Bytes = 3.6 MiB
Load Address: 00000000
Entry Point: 00000000
Verifying Checksum ... OK
## Flattened Device Tree blob at 02a00000
Booting using the fdt blob at 0x02a00000 Loading Kernel Image ... OK
OK
Loading Ramdisk to 1fc62000, end 1ffffcca ... OK Loading Device Tree to 1fc5e000, end 1fc61c05 ... OK

Starting kernel ...

Uncompressing Linux... done, booting the kernel.

[    0.000000] Booting Linux on physical CPU 0x0

[    0.000000] Linux version 3.10.0-rc3-00119-ga93cb29-dirty (sorenb at xsjandreislx) (gcc version 4.7.2 (Sourcery CodeBench Lite 2012.09-104) ) #85 SMP PREEMPT Fri May 31 11:43:25 PDT 2013

[    0.000000] CPU: ARMv7 Processor [413fc090] revision 0 (ARMv7), cr=18c5387d

[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache

[    0.000000] Machine: Xilinx Zynq Platform, model: Zynq ZC702 Development Board

[    0.000000] bootconsole [earlycon0] enabled

[    0.000000] cma: CMA: reserved 16 MiB at 2e800000

[    0.000000] Memory policy: ECC disabled, Data cache writealloc

[    0.000000] PERCPU: Embedded 9 pages/cpu @c1475000 s14144 r8192 d14528 u36864

[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 260624

[    0.000000] Kernel command line: console=ttyPS0,115200 earlyprintk

[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)

[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)

[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)

[    0.000000] Memory: 1024MB = 1024MB total

[    0.000000] Memory: 1006620k/1006620k available, 41956k reserved, 270336K highmem

[    0.000000] Virtual kernel memory layout:

[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)

[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)

[    0.000000]     vmalloc : 0xf0000000 - 0xff000000   ( 240 MB)

[    0.000000]     lowmem  : 0xc0000000 - 0xef800000   ( 760 MB)

[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)

[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)

[    0.000000]       .text : 0xc0008000 - 0xc06338a4   (6319 kB)

[    0.000000]       .init : 0xc0634000 - 0xc0685740   ( 326 kB)

[    0.000000]       .data : 0xc0686000 - 0xc06d0ee0   ( 300 kB)

[    0.000000]        .bss : 0xc06d0ee0 - 0xc0c615d0   (5698 kB)

[    0.000000] Preemptible hierarchical RCU implementation.

[    0.000000] 	RCU lockdep checking is enabled.

[    0.000000] 	Additional per-CPU info printed with stalls.

[    0.000000] 	RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2.

[    0.000000] NR_IRQS:16 nr_irqs:16 16

[    0.000000] slcr mapped to f0002000

[    0.000000] ttc0 #0 at f0004000, irq=43

[    0.000000] sched_clock: 32 bits at 100 Hz, resolution 10000000ns, wraps every 4294967286ms

[    0.000000] Console: colour dummy device 80x30

[    0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar

[    0.000000] ... MAX_LOCKDEP_SUBCLASSES:  8

[    0.000000] ... MAX_LOCK_DEPTH:          48

[    0.000000] ... MAX_LOCKDEP_KEYS:        8191

[    0.000000] ... CLASSHASH_SIZE:          4096

[    0.000000] ... MAX_LOCKDEP_ENTRIES:     16384

[    0.000000] ... MAX_LOCKDEP_CHAINS:      32768

[    0.000000] ... CHAINHASH_SIZE:          16384

[    0.000000]  memory used by lock dependency info: 3695 kB

[    0.000000]  per task-struct memory footprint: 1152 bytes

[    0.060000] Calibrating delay loop... 1332.01 BogoMIPS (lpj=6660096)

[    0.150000] pid_max: default: 32768 minimum: 301

[    0.150000] Mount-cache hash table entries: 512

[    0.160000] CPU: Testing write buffer coherency: ok

[    0.160000] ftrace: allocating 15863 entries in 47 pages

[    0.200000] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000

[    0.200000] Setting up static identity map for 0xc04552d8 - 0xc0455330

[    0.210000] CPU1: Booted secondary processor

[    0.300000] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001

[    0.300000] Brought up 2 CPUs

[    0.300000] SMP: Total of 2 processors activated (2664.03 BogoMIPS).

[    0.310000] CPU: All CPU(s) started in SVC mode.

[    0.320000] devtmpfs: initialized

[    0.340000] NET: Registered protocol family 16

[    0.340000] DMA: preallocated 256 KiB pool for atomic coherent allocations

[    0.360000] L310 cache controller enabled

[    0.360000] l2x0: 8 ways, CACHE_ID 0x410000c8, AUX_CTRL 0x72360000, Cache size: 524288 B

[    0.370000] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.

[    0.370000] hw-breakpoint: maximum watchpoint size is 4 bytes.

[    0.450000] bio: create slab <bio-0> at 0

[    0.460000] SCSI subsystem initialized

[    0.460000] usbcore: registered new interface driver usbfs

[    0.460000] usbcore: registered new interface driver hub

[    0.470000] usbcore: registered new device driver usb

[    0.480000] Switching to clocksource ttc_clocksource

[    0.650000] NET: Registered protocol family 2

[    0.650000] TCP established hash table entries: 8192 (order: 4, 65536 bytes)

[    0.650000] TCP bind hash table entries: 8192 (order: 6, 294912 bytes)

[    0.670000] TCP: Hash tables configured (established 8192 bind 8192)

[    0.670000] TCP: reno registered

[    0.670000] UDP hash table entries: 512 (order: 3, 40960 bytes)

[    0.680000] UDP-Lite hash table entries: 512 (order: 3, 40960 bytes)

[    0.690000] NET: Registered protocol family 1

[    0.690000] RPC: Registered named UNIX socket transport module.

[    0.690000] RPC: Registered udp transport module.

[    0.700000] RPC: Registered tcp transport module.

[    0.700000] RPC: Registered tcp NFSv4.1 backchannel transport module.

[    0.710000] Trying to unpack rootfs image as initramfs...

[    1.250000] Freeing initrd memory: 3700K (dfc62000 - dffff000)

[    1.260000] bounce pool size: 64 pages

[    1.260000] jffs2: version 2.2. (NAND) (SUMMARY)  ?? 2001-2006 Red Hat, Inc.

[    1.260000] msgmni has been set to 1477

[    1.290000] io scheduler noop registered

[    1.290000] io scheduler deadline registered

[    1.290000] io scheduler cfq registered (default)

[    1.310000] e000?[    1.310000] console [ttyPS0] enabled, bootconsole disabled
[    1.310000] console [ttyPS0] enabled, bootconsole disabled

[    1.360000] brd: module loaded
[    1.380000] loop: module loaded
[    1.400000] usbcore: registered new interface driver usb-storage
[    1.410000] mousedev: PS/2 mouse device common for all mice
[    1.420000] i2c /dev entries driver
[    1.430000] mpcore_wdt: MPcore Watchdog Timer: 0.1. mpcore_noboot=0 mpcore_margin=60 sec (nowayout= 0)
[    1.440000] cpuidle: using governor ladder
[    1.440000] cpuidle: using governor menu
[    1.440000] sdhci: Secure Digital Host Controller Interface driver
[    1.450000] sdhci: Copyright(c) Pierre Ossman
[    1.460000] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.460000] usbcore: registered new interface driver usbhid
[    1.470000] usbhid: USB HID core driver
[    1.470000] TCP: cubic registered
[    1.480000] NET: Registered protocol family 17
[    1.480000] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[    1.490000] Registering SWP/SWPB emulation handler
[    1.500000] drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
[    1.510000] Freeing unused kernel memory: 324K (c0634000 - c0685000)

Starting logging: OK
Starting mdev...
mdev: bad line 25
mdev: bad line 26
mdev: bad line 27
mdev: bad line 28
mdev: bad line 29
mdev: bad line 32
mdev: bad line 33
mdev: bad line 34
mdev: bad line 35
Initializing random number generator... done.
Starting network...
Starting dropbear sshd: generating rsa key... generating dsa key... OK

Zynq Busybox System

zynq login: root
Password:

# lsmod
# modprobe clk_notif_dbg
[  508.310000] clk_notif_dbg clk_notif_dbg.1: clk_get()
[  508.320000] clk_notif_dbg clk_notif_dbg.1: clk_prepare()
[  508.320000] clk_notif_dbg clk_notif_dbg.1: clk_enable()
[  508.330000] clk_notif_dbg clk_notif_dbg.1: clk_notifier_register()
[  508.330000] clk_notif_dbg clk_notif_dbg.1: probe done
# 
# modprobe clk_notif_dbg -r
[  512.230000] clk_notif_dbg clk_notif_dbg.1: clk_notifier_unregister()
[  512.240000] clk_notif_dbg clk_notif_dbg.1: clk_disable()
[  512.240000] clk_notif_dbg clk_notif_dbg.1: clk_unprepare()
[  512.250000] clk_notif_dbg clk_notif_dbg.1: clk_put()
[  512.250000] clk_notif_dbg clk_notif_dbg.1: remove done
# 
# modprobe clk_notif_dbg -r
# modprobe clk_notif_dbg
[  515.290000] clk_notif_dbg clk_notif_dbg.1: clk_get()
[  515.290000] clk_notif_dbg clk_notif_dbg.1: clk_prepare()
[  515.300000] clk_notif_dbg clk_notif_dbg.1: clk_enable()
[  515.300000] clk_notif_dbg clk_notif_dbg.1: clk_notifier_register()
[  515.310000] clk_notif_dbg clk_notif_dbg.1: probe done
# 
# modprobe clk_notif_dbg
# modprobe clk_notif_dbg -r
[  517.040000] clk_notif_dbg clk_notif_dbg.1: clk_notifier_unregister()
[  517.040000] Unable to handle kernel paging request at virtual address 00df3008
[  517.050000] pgd = ed858000
[  517.050000] [00df3008] *pgd=00000000
[  517.060000] Internal error: Oops: 5 [#1] PREEMPT SMP ARM
[  517.060000] Modules linked in: clk_notif_dbg(O-) [last unloaded: clk_notif_dbg]
[  517.060000] CPU: 1 PID: 499 Comm: modprobe Tainted: G           O 3.10.0-rc3-00119-ga93cb29-dirty #85
[  517.060000] task: ee1e0180 ti: ee3e6000 task.ti: ee3e6000
[  517.060000] PC is at srcu_readers_seq_idx+0x48/0x84
[  517.060000] LR is at srcu_readers_seq_idx+0x60/0x84
[  517.060000] pc : [<c0052720>]    lr : [<c0052738>]    psr: 80070013
[  517.060000] sp : ee3e7d48  ip : 00000000  fp : ee3e7d6c
[  517.060000] r10: 00000000  r9 : ee3e6000  r8 : 00000000
[  517.060000] r7 : ed84fe4c  r6 : c068ec90  r5 : c068e430  r4 : 00000000
[  517.060000] r3 : 00df3000  r2 : 00000000  r1 : 00000002  r0 : 00000000
[  517.060000] Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
[  517.060000] Control: 18c5387d  Table: 2d85804a  DAC: 00000015
[  517.060000] Process modprobe (pid: 499, stack limit = 0xee3e6238)
[  517.060000] Stack: (0xee3e7d48 to 0xee3e8000)
[  517.060000] 7d40:                   ee3e7dd4 ed84fe4c 00000000 00000002 c045719c 00000002
[  517.060000] 7d60: ee3e7da4 ee3e7d70 c0052790 c00526e4 ee3e6000 00000002 ee3e7da4 ed84fe4c
[  517.060000] 7d80: ed84fe80 00000001 00000000 00000002 ee3e6000 00000000 ee3e7dcc ee3e7da8
[  517.060000] 7da0: c00528b0 c0052768 ed84fe4c ee3e7dd4 00000001 00000000 ed84fe54 00000002
[  517.060000] 7dc0: ee3e7e2c ee3e7dd0 c0052c30 c0052864 ee3e7dfc 00000000 c0052d38 00000000
[  517.060000] 7de0: 00000000 dead4ead ffffffff ffffffff c06d8880 00000000 00000000 c0557b5a
[  517.060000] 7e00: ee3e7e00 ee3e7e00 ed84fe04 00000000 bf008704 00000081 c000f044 00000000
[  517.060000] 7e20: ee3e7e3c ee3e7e30 c0052d14 c0052b28 ee3e7e5c ee3e7e40 c0053a08 c0052cf4
[  517.060000] 7e40: ee002dc0 ed84fe00 ee002dc0 bf008704 ee3e7e7c ee3e7e60 c0375a78 c00539ac
[  517.060000] 7e60: 60070013 ee150410 bf008700 ee150444 ee3e7e94 ee3e7e80 bf008034 c0375a08
[  517.060000] 7e80: ee150410 bf008548 ee3e7ea4 ee3e7e98 c02bb974 bf00800c ee3e7ebc ee3e7ea8
[  517.060000] 7ea0: c02b9bf8 c02bb95c ee150410 bf008548 ee3e7edc ee3e7ec0 c02ba680 c02b9b78
[  517.060000] 7ec0: 00000000 bf008548 00000000 c06af670 ee3e7efc ee3e7ee0 c02b99c4 c02ba5f0
[  517.060000] 7ee0: ee3f9840 bf008548 00000000 bee66e83 ee3e7f14 ee3e7f00 c02bace4 c02b9904
[  517.060000] 7f00: bf008588 00000000 ee3e7f24 ee3e7f18 c02bbb44 c02bac9c ee3e7f34 ee3e7f28
[  517.060000] 7f20: bf0081f8 c02bbb34 ee3e7fa4 ee3e7f38 c00835e4 bf0081f0 c005815c 00000000
[  517.060000] 7f40: bf008588 00000880 ee3e7f3c 5f6b6c63 69746f6e 62645f66 ee3e0067 ee3e7f68
[  517.060000] 7f60: c0079424 c00791a8 00000000 00000000 bee66e83 00108250 ee3e7f94 ee3e7f88
[  517.060000] 7f80: c00794c4 000792dc 00000000 00000000 bee66e83 00108250 00000000 ee3e7fa8
[  517.060000] 7fa0: c000edc0 c00833f0 00000000 bee66e83 bee66e83 00000880 00108250 00000000
[  517.060000] 7fc0: 00000000 bee66e83 00108250 00000081 00000001 bee66d74 000ffcc0 00000000
[  517.060000] 7fe0: b6e7afd0 bee669e4 000370bc b6e7afdc 60070010 bee66e83 f8ce7acf b7b173d5
[  517.060000] [<c0052720>] (srcu_readers_seq_idx+0x48/0x84) from [<c0052790>] (try_check_zero+0x34/0xfc)
[  517.060000] [<c0052790>] (try_check_zero+0x34/0xfc) from [<c00528b0>] (srcu_advance_batches+0x58/0x114)
[  517.060000] [<c00528b0>] (srcu_advance_batches+0x58/0x114) from [<c0052c30>] (__synchronize_srcu+0x114/0x1ac)
[  517.060000] [<c0052c30>] (__synchronize_srcu+0x114/0x1ac) from [<c0052d14>] (synchronize_srcu+0x2c/0x34)
[  517.060000] [<c0052d14>] (synchronize_srcu+0x2c/0x34) from [<c0053a08>] (srcu_notifier_chain_unregister+0x68/0x74)
[  517.060000] [<c0053a08>] (srcu_notifier_chain_unregister+0x68/0x74) from [<c0375a78>] (clk_notifier_unregister+0x7c/0xc0)
[  517.060000] [<c0375a78>] (clk_notifier_unregister+0x7c/0xc0) from [<bf008034>] (clk_notif_dbg_remove+0x34/0x9c [clk_notif_dbg])
[  517.060000] [<bf008034>] (clk_notif_dbg_remove+0x34/0x9c [clk_notif_dbg]) from [<c02bb974>] (platform_drv_remove+0x24/0x28)
[  517.060000] [<c02bb974>] (platform_drv_remove+0x24/0x28) from [<c02b9bf8>] (__device_release_driver+0x8c/0xd4)
[  517.060000] [<c02b9bf8>] (__device_release_driver+0x8c/0xd4) from [<c02ba680>] (driver_detach+0x9c/0xc4)
[  517.060000] [<c02ba680>] (driver_detach+0x9c/0xc4) from [<c02b99c4>] (bus_remove_driver+0xcc/0xfc)
[  517.060000] [<c02b99c4>] (bus_remove_driver+0xcc/0xfc) from [<c02bace4>] (driver_unregister+0x54/0x78)
[  517.060000] [<c02bace4>] (driver_unregister+0x54/0x78) from [<c02bbb44>] (platform_driver_unregister+0x1c/0x20)
[  517.060000] [<c02bbb44>] (platform_driver_unregister+0x1c/0x20) from [<bf0081f8>] (clk_notif_dbg_driver_exit+0x14/0x1c [clk_notif_dbg])
[  517.060000] [<bf0081f8>] (clk_notif_dbg_driver_exit+0x14/0x1c [clk_notif_dbg]) from [<c00835e4>] (SyS_delete_module+0x200/0x28c)
[  517.060000] [<c00835e4>] (SyS_delete_module+0x200/0x28c) from [<c000edc0>] (ret_fast_syscall+0x0/0x48)
[  517.060000] Code: e5973004 e7911102 e0833001 e2881002 (e7933101) 
[  517.490000] ---[ end trace 389463afcdb5d46a ]---
Segmentation fault
# 

-------------- next part --------------
A non-text attachment was scrubbed...
Name: clk_notif_dbg.c
Type: text/x-csrc
Size: 2017 bytes
Desc: not available
URL: <http://lists.infradead.org/pipermail/linux-arm-kernel/attachments/20130531/aba1a917/attachment-0002.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0001-zynq-Clock-notify-debug-on-zc702.patch
Type: text/x-diff
Size: 1468 bytes
Desc: not available
URL: <http://lists.infradead.org/pipermail/linux-arm-kernel/attachments/20130531/aba1a917/attachment-0003.bin>

Quoting S?ren Brinkmann (2013-05-31 12:12:07)

Soren,

I only took a quick look at this so the following is a shot in the dark. notifier_block->next should be protected by an RCU lock, and the way you open-code the initialization struck me as a bit weird. Can you change your code to the following and let me know if it makes any difference?

static struct notifier_block nb = {
        .notifier_call = clk_notif_dbg_cb;
};

static int clk_notif_dbg_cb(struct notifier_block *nb,
unsigned long event, void *data)

{
        pr_info("clk_notif_dbg_cb\n");

        return NOTIFY_OK;
}

static int clk_notif_dbg_probe(struct platform_device *pdev)

{
        ...
        if (clk_notifier_register(clk, &nb))
                dev_warn(&pdev->dev, "clk_notifier_register failed\n");
        ...

That is a small difference, but that style of initializing the notifier_block has always worked for me when using clk rate-change notifiers. However I'm sure the bug you mention is far more evil and nefarious than that ;-)

Regards,
Mike

Hi Mike,

I changed the module like this (I hope this is what you suggested):

	8,9d7
	< static struct notifier_block nb;
	< 
	17a16,19
	> static struct notifier_block nb = {
	>       .notifier_call = clk_notif_dbg_cb
	> };
	> 
	20,22d21
	<       nb.next = NULL;
	<       nb.notifier_call = clk_notif_dbg_cb;
	<

The result is the same. It crashes in srcu_readers_seq_idx().

Thanks,
S?ren

Hi, Sören Brinkmann

I guess:

modprobe clk_notif_dbg

modprobe clk_notif_dbg -r  # memory corrupt here
modprobe clk_notif_dbg     # access corrupted memroy, but no visiable bug
modprobe clk_notif_dbg -r  # access corrupted memroy, BUG

How the first "modprobe clk_notif_dbg -r" corrupt memroy:

=========

int clk_notifier_unregister(struct clk *clk, struct notifier_block *nb)

{
	struct clk_notifier *cn = NULL;
	int ret = -EINVAL;

	if (!clk || !nb)
		return -EINVAL;

	clk_prepare_lock();

	list_for_each_entry(cn, &clk_notifier_list, node)
		if (cn->clk == clk)
			break;

	if (cn->clk == clk) {
		ret = srcu_notifier_chain_unregister(&cn->notifier_head, nb);

		clk->notifier_count--;

		/* XXX the notifier code should handle this better */
		if (!cn->notifier_head.head) {
			srcu_cleanup_notifier_head(&cn->notifier_head);

===========> the code forgot to remove @cn from the clk_notifier_list ===========> the second "modprobe clk_notif_dbg" will the same @clk and use the same corrupt @cn

			kfree(cn);
		}

	} else {
		ret = -ENOENT;
	}

	clk_prepare_unlock();

	return ret;
}

===========

Could you retry with the following patch?

Thanks,
Lai

From: Lai Jiangshan <[email protected]>
Date: Mon, 3 Jun 2013 16:59:50 +0800
Subject: [PATCH] clk: remove the clk_notifier from clk_notifier_list before
free it
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

The @cn is stay in @clk_notifier_list after it is freed, it cause memory corruption.

Example, if @clk is registered(first), unregistered(first), registered(second), unregistered(second).

The freed @cn will be used when @clk is registered(second), and the bug will be happened when @clk is unregistered(second):

[  517.040000] clk_notif_dbg clk_notif_dbg.1: clk_notifier_unregister()
[  517.040000] Unable to handle kernel paging request at virtual address 00df3008
[  517.050000] pgd = ed858000
[  517.050000] [00df3008] *pgd=00000000
[  517.060000] Internal error: Oops: 5 [#1] PREEMPT SMP ARM
[  517.060000] Modules linked in: clk_notif_dbg(O-) [last unloaded: clk_notif_dbg]
[  517.060000] CPU: 1 PID: 499 Comm: modprobe Tainted: G           O 3.10.0-rc3-00119-ga93cb29-dirty #85
[  517.060000] task: ee1e0180 ti: ee3e6000 task.ti: ee3e6000
[  517.060000] PC is at srcu_readers_seq_idx+0x48/0x84
[  517.060000] LR is at srcu_readers_seq_idx+0x60/0x84
[  517.060000] pc : [<c0052720>]    lr : [<c0052738>]    psr: 80070013
[  517.060000] sp : ee3e7d48  ip : 00000000  fp : ee3e7d6c
[  517.060000] r10: 00000000  r9 : ee3e6000  r8 : 00000000
[  517.060000] r7 : ed84fe4c  r6 : c068ec90  r5 : c068e430  r4 : 00000000
[  517.060000] r3 : 00df3000  r2 : 00000000  r1 : 00000002  r0 : 00000000
[  517.060000] Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
[  517.060000] Control: 18c5387d  Table: 2d85804a  DAC: 00000015
[  517.060000] Process modprobe (pid: 499, stack limit = 0xee3e6238)
[  517.060000] Stack: (0xee3e7d48 to 0xee3e8000)
....
[  517.060000] [<c0052720>] (srcu_readers_seq_idx+0x48/0x84) from [<c0052790>] (try_check_zero+0x34/0xfc)
[  517.060000] [<c0052790>] (try_check_zero+0x34/0xfc) from [<c00528b0>] (srcu_advance_batches+0x58/0x114)
[  517.060000] [<c00528b0>] (srcu_advance_batches+0x58/0x114) from [<c0052c30>] (__synchronize_srcu+0x114/0x1ac)
[  517.060000] [<c0052c30>] (__synchronize_srcu+0x114/0x1ac) from [<c0052d14>] (synchronize_srcu+0x2c/0x34)
[  517.060000] [<c0052d14>] (synchronize_srcu+0x2c/0x34) from [<c0053a08>] (srcu_notifier_chain_unregister+0x68/0x74)
[  517.060000] [<c0053a08>] (srcu_notifier_chain_unregister+0x68/0x74) from [<c0375a78>] (clk_notifier_unregister+0x7c/0xc0)
[  517.060000] [<c0375a78>] (clk_notifier_unregister+0x7c/0xc0) from [<bf008034>] (clk_notif_dbg_remove+0x34/0x9c [clk_notif_dbg])
[  517.060000] [<bf008034>] (clk_notif_dbg_remove+0x34/0x9c [clk_notif_dbg]) from [<c02bb974>] (platform_drv_remove+0x24/0x28)
[  517.060000] [<c02bb974>] (platform_drv_remove+0x24/0x28) from [<c02b9bf8>] (__device_release_driver+0x8c/0xd4)
[  517.060000] [<c02b9bf8>] (__device_release_driver+0x8c/0xd4) from [<c02ba680>] (driver_detach+0x9c/0xc4)
[  517.060000] [<c02ba680>] (driver_detach+0x9c/0xc4) from [<c02b99c4>] (bus_remove_driver+0xcc/0xfc)
[  517.060000] [<c02b99c4>] (bus_remove_driver+0xcc/0xfc) from [<c02bace4>] (driver_unregister+0x54/0x78)
[  517.060000] [<c02bace4>] (driver_unregister+0x54/0x78) from [<c02bbb44>] (platform_driver_unregister+0x1c/0x20)
[  517.060000] [<c02bbb44>] (platform_driver_unregister+0x1c/0x20) from [<bf0081f8>] (clk_notif_dbg_driver_exit+0x14/0x1c [clk_notif_dbg])
[  517.060000] [<bf0081f8>] (clk_notif_dbg_driver_exit+0x14/0x1c [clk_notif_dbg]) from [<c00835e4>] (SyS_delete_module+0x200/0x28c)
[  517.060000] [<c00835e4>] (SyS_delete_module+0x200/0x28c) from [<c000edc0>] (ret_fast_syscall+0x0/0x48)
[  517.060000] Code: e5973004 e7911102 e0833001 e2881002 (e7933101)

---
 drivers/clk/clk.c |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)

index 934cfd1..1144e8c 100644
@@ -1955,6 +1955,7 @@ int clk_notifier_unregister(struct clk *clk, struct notifier_block *nb)
 		/* XXX the notifier code should handle this better */
 		if (!cn->notifier_head.head) {
 			srcu_cleanup_notifier_head(&cn->notifier_head);
+			list_del(&cn->node);
 			kfree(cn);
 		}
 

1.7.4.4

Hi Lai,

Thanks for the patch. This fixes it. I can add/remove my module, and it didn't crash since.
I had some trouble applying it though, due to some encoding hiccups. I think the '?' in my name might be the culprit. I never know where things go wrong, whether it's format-patch, or something in the email transport, the sender or receiver side... But well, looks like full UTF-8 support is missing somewhere.

S?ren

Quoting Lai Jiangshan (2013-06-03 02:17:15)

Thanks! I picked this up for the next set of fixes.

Regards,
Mike