ABBA deadlock in Common Clock Framework

From: Tomasz Figa
Date: Wed Jul 02 2014 - 06:59:45 EST


Hi All,

While testing linux-next (next-20140625) on Exynos4412-based TRATS2
board, from time to time I hit a deadlock between clk_disable_unused()
of Common Clock Framework and parallel clk_prepare() from s3c24xx-i2c
driver.

I believe the following is happening (in processes 1 and 2):
1: clk_disable_unused()
1: clk_prepare_lock()
1: mutex_lock(clk prepare mutex) // lock A
1: max77686_clk_is_prepared()
1: regmap_read()
2: regulator_set_voltage()
2: regmap_read()
2: mutex_lock(max77686 regmap mutex) // lock B
2: i2c_transfer()
2: s3c24xx_i2c_xfer()
2: clk_unprepare()
2: clk_prepare_lock()
2: mutex_lock(clk prepare mutex) // lock A
1: mutex_lock(max77686 regmap mutex) // lock B
1,2: BOOM!

I suppose this is a general problem affecting any MFD device that is
also a clock provider, but I clearly don't have a good idea what to do
about it.

Full boot log below:

> Uncompressing Linux... done, booting the kernel.
> [ 0.000000] Booting Linux on physical CPU 0xa00
> [ 0.000000] Linux version 3.16.0-rc2-next-20140625-00007-g993e726d-dirty (t.figa@AMDC1227) (gcc version 4.8.2 (Gentoo 4.8.2 p1.1, pie-0.5.8) ) #905 SMP PREEMPT Tue Jul 1 17:48:42 CEST 2014
> [ 0.000000] CPU: ARMv7 Processor [413fc090] revision 0 (ARMv7), cr=10c5387d
> [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
> [ 0.000000] Machine model: Samsung Trats 2 based on Exynos4412
> [ 0.000000] bootconsole [earlycon0] enabled
> [ 0.000000] debug: ignoring loglevel setting.
> [ 0.000000] Memory policy: Data cache writealloc
> [ 0.000000] On node 0 totalpages: 262144
> [ 0.000000] free_area_init_node: node 0, pgdat c063bc00, node_mem_map eeff0000
> [ 0.000000] Normal zone: 1520 pages used for memmap
> [ 0.000000] Normal zone: 0 pages reserved
> [ 0.000000] Normal zone: 194560 pages, LIFO batch:31
> [ 0.000000] HighMem zone: 528 pages used for memmap
> [ 0.000000] HighMem zone: 67584 pages, LIFO batch:15
> [ 0.000000] Running under secure firmware.
> [ 0.000000] PERCPU: Embedded 7 pages/cpu @eefa3000 s7744 r8192 d12736 u32768
> [ 0.000000] pcpu-alloc: s7744 r8192 d12736 u32768 alloc=8*4096
> [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
> [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 260624
> [ 0.000000] Kernel command line: root=/dev/mmcblk0p5 rootwait console=ttySAC2,115200n8 earlyprintk ignore_loglevel no_console_suspend
> [ 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: 1032564K/1048576K available (4329K kernel code, 266K rwdata, 1480K rodata, 275K init, 272K bss, 16012K reserved, 270336K highmem)
> [ 0.000000] Virtual kernel memory layout:
> [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
> [ 0.000000] fixmap : 0xffc00000 - 0xffe00000 (2048 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 - 0xc05b47c0 (5810 kB)
> [ 0.000000] .init : 0xc05b5000 - 0xc05f9e40 ( 276 kB)
> [ 0.000000] .data : 0xc05fa000 - 0xc063c800 ( 266 kB)
> [ 0.000000] .bss : 0xc063c80c - 0xc0680a00 ( 273 kB)
> [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
> [ 0.000000] Preemptible hierarchical RCU implementation.
> [ 0.000000] RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=4.
> [ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
> [ 0.000000] NR_IRQS:16 nr_irqs:16 16
> [ 0.000000] L2C: failed to init: -19
> [ 0.000000] Exynos4x12 clocks: sclk_apll = 800000000, sclk_mpll = 800000000
> [ 0.000000] sclk_epll = 96000000, sclk_vpll = 108000000, arm_clk = 800000000
> [ 0.000012] sched_clock: 64 bits at 24MHz, resolution 41ns, wraps every 2863311519744ns
> [ 0.008211] Console: colour dummy device 80x30
> [ 0.012619] Calibrating delay loop... 1590.88 BogoMIPS (lpj=3977216)
> [ 0.037727] pid_max: default: 32768 minimum: 301
> [ 0.042578] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
> [ 0.049146] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
> [ 0.056985] CPU: Testing write buffer coherency: ok
> [ 0.062107] missing device node for CPU 0
> [ 0.066114] missing device node for CPU 1
> [ 0.070169] missing device node for CPU 2
> [ 0.074212] missing device node for CPU 3
> [ 0.078298] CPU0: thread -1, cpu 0, socket 10, mpidr 80000a00
> [ 0.084903] Setting up static identity map for 0x4041c888 - 0x4041c8e0
> [ 0.120728] CPU1: Booted secondary processor
> [ 0.140009] CPU1: thread -1, cpu 1, socket 10, mpidr 80000a01
> [ 0.150709] CPU2: Booted secondary processor
> [ 0.170010] CPU2: thread -1, cpu 2, socket 10, mpidr 80000a02
> [ 0.180722] CPU3: Booted secondary processor
> [ 0.200010] CPU3: thread -1, cpu 3, socket 10, mpidr 80000a03
> [ 0.200156] Brought up 4 CPUs
> [ 0.233514] SMP: Total of 4 processors activated.
> [ 0.238302] CPU: All CPU(s) started in SVC mode.
> [ 0.243984] devtmpfs: initialized
> [ 0.252902] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
> [ 0.261509] pinctrl core: initialized pinctrl subsystem
> [ 0.267742] regulator-dummy: no parameters
> [ 0.287447] NET: Registered protocol family 16
> [ 0.292766] DMA: preallocated 256 KiB pool for atomic coherent allocations
> [ 0.307018] exynos-audss-clk 3810000.clock-controller: setup completed
> [ 0.332875] gpiochip_add: registered GPIOs 0 to 7 on device: gpa0
> [ 0.338935] gpiochip_add: registered GPIOs 8 to 13 on device: gpa1
> [ 0.345185] gpiochip_add: registered GPIOs 14 to 21 on device: gpb
> [ 0.351419] gpiochip_add: registered GPIOs 22 to 26 on device: gpc0
> [ 0.357762] gpiochip_add: registered GPIOs 27 to 31 on device: gpc1
> [ 0.364087] gpiochip_add: registered GPIOs 32 to 35 on device: gpd0
> [ 0.370433] gpiochip_add: registered GPIOs 36 to 39 on device: gpd1
> [ 0.376762] gpiochip_add: registered GPIOs 40 to 47 on device: gpf0
> [ 0.383106] gpiochip_add: registered GPIOs 48 to 55 on device: gpf1
> [ 0.389434] gpiochip_add: registered GPIOs 56 to 63 on device: gpf2
> [ 0.395780] gpiochip_add: registered GPIOs 64 to 69 on device: gpf3
> [ 0.402108] gpiochip_add: registered GPIOs 70 to 77 on device: gpj0
> [ 0.408440] gpiochip_add: registered GPIOs 78 to 82 on device: gpj1
> [ 0.416519] gpiochip_add: registered GPIOs 83 to 89 on device: gpk0
> [ 0.422750] gpiochip_add: registered GPIOs 90 to 96 on device: gpk1
> [ 0.429083] gpiochip_add: registered GPIOs 97 to 103 on device: gpk2
> [ 0.435492] gpiochip_add: registered GPIOs 104 to 110 on device: gpk3
> [ 0.442009] gpiochip_add: registered GPIOs 111 to 117 on device: gpl0
> [ 0.448510] gpiochip_add: registered GPIOs 118 to 119 on device: gpl1
> [ 0.455081] gpiochip_add: registered GPIOs 120 to 127 on device: gpl2
> [ 0.461548] gpiochip_add: registered GPIOs 128 to 135 on device: gpm0
> [ 0.468044] gpiochip_add: registered GPIOs 136 to 142 on device: gpm1
> [ 0.474548] gpiochip_add: registered GPIOs 143 to 147 on device: gpm2
> [ 0.481055] gpiochip_add: registered GPIOs 148 to 155 on device: gpm3
> [ 0.487563] gpiochip_add: registered GPIOs 156 to 163 on device: gpm4
> [ 0.494074] gpiochip_add: registered GPIOs 164 to 169 on device: gpy0
> [ 0.500584] gpiochip_add: registered GPIOs 170 to 173 on device: gpy1
> [ 0.507094] gpiochip_add: registered GPIOs 174 to 179 on device: gpy2
> [ 0.513603] gpiochip_add: registered GPIOs 180 to 187 on device: gpy3
> [ 0.520113] gpiochip_add: registered GPIOs 188 to 195 on device: gpy4
> [ 0.526623] gpiochip_add: registered GPIOs 196 to 203 on device: gpy5
> [ 0.533134] gpiochip_add: registered GPIOs 204 to 211 on device: gpy6
> [ 0.539659] gpiochip_add: registered GPIOs 212 to 219 on device: gpx0
> [ 0.546159] gpiochip_add: registered GPIOs 220 to 227 on device: gpx1
> [ 0.552667] gpiochip_add: registered GPIOs 228 to 235 on device: gpx2
> [ 0.559174] gpiochip_add: registered GPIOs 236 to 243 on device: gpx3
> [ 0.567567] gpiochip_add: registered GPIOs 244 to 250 on device: gpz
> [ 0.574712] gpiochip_add: registered GPIOs 251 to 258 on device: gpv0
> [ 0.581130] gpiochip_add: registered GPIOs 259 to 266 on device: gpv1
> [ 0.587615] gpiochip_add: registered GPIOs 267 to 274 on device: gpv2
> [ 0.594130] gpiochip_add: registered GPIOs 275 to 282 on device: gpv3
> [ 0.600629] gpiochip_add: registered GPIOs 283 to 284 on device: gpv4
> [ 0.616275] EXYNOS4x12 PMU Initialize
> [ 0.667979] of_get_named_gpiod_flags exited with status 0
> [ 0.673790] VMEM_VDD_2.8V: 2800 mV
> [ 0.677531] of_get_named_gpiod_flags exited with status 0
> [ 0.683339] CAM_SENSOR_A: 2800 mV
> [ 0.686996] of_get_named_gpiod_flags exited with status 0
> [ 0.692796] LCD_VDD_2.2V: 2200 mV
> [ 0.696455] of_get_named_gpiod_flags exited with status 0
> [ 0.702256] CAM_AF: 2800 mV
> [ 0.705409] of_get_named_gpiod_flags exited with status 0
> [ 0.711172] CAM_ISP_CORE_1.2V_EN: 1200 mV
> [ 0.715489] of_get_named_gpiod_flags exited with status 0
> [ 0.721255] LED_A_3.0V: 3000 mV
> [ 0.729652] SCSI subsystem initialized
> [ 0.734917] usbcore: registered new interface driver usbfs
> [ 0.740658] usbcore: registered new interface driver hub
> [ 0.746302] usbcore: registered new device driver usb
> [ 0.752844] s3c-i2c 13860000.i2c: slave address 0x10
> [ 0.757776] s3c-i2c 13860000.i2c: bus frequency set to 390 KHz
> [ 0.764887] s3c-i2c 13860000.i2c: i2c-0: S3C I2C adapter
> [ 0.770462] s3c-i2c 13890000.i2c: slave address 0x10
> [ 0.775409] s3c-i2c 13890000.i2c: bus frequency set to 390 KHz
> [ 0.782528] s3c-i2c 13890000.i2c: i2c-3: S3C I2C adapter
> [ 0.788120] s3c-i2c 138d0000.i2c: slave address 0x10
> [ 0.793048] s3c-i2c 138d0000.i2c: bus frequency set to 97 KHz
> [ 0.800838] max77686 7-0009: device found
> [ 0.809622] VALIVE_1.0V_AP: 1000 mV
> [ 0.815406] VM1M2_1.2V_AP: 1200 mV
> [ 0.820988] VCC_1.8V_AP: 1800 mV
> [ 0.826434] VCC_2.8V_AP: 2800 mV
> [ 0.831844] VCC_1.8V_IO: 1800 mV
> [ 0.839038] VMPLL_1.0V_AP: 1000 mV
> [ 0.846363] VPLL_1.0V_AP: 1000 mV
> [ 0.851106] VMIPI_1.0V: 1000 mV
> [ 0.856936] CAM_ISP_MIPI_1.2V: 1200 mV
> [ 0.862121] VMIPI_1.8V: 1800 mV
> [ 0.869222] VABB1_1.95V: 1950 mV
> [ 0.873902] VUOTG_3.0V: 3000 mV
> [ 0.878469] NFC_AVDD_1.8V: 1800 mV
> [ 0.885868] VABB2_1.95V: 1950 mV
> [ 0.890618] VHSIC_1.0V: 1000 mV
> [ 0.895185] VHSIC_1.8V: 1800 mV
> [ 0.899714] CAM_SENSOR_CORE_1.2V: 1200 mV
> [ 0.905197] CAM_ISP_SEN_IO_1.8V: 1800 mV
> [ 0.910585] VT_CAM_1.8V: 1800 mV
> [ 0.915257] VDDQ_PRE_1.8V: 1800 mV
> [ 0.920072] VTF_2.8V: 2800 mV
> [ 0.925274] VMEM_VDD_2.8V: 2800 mV
> [ 0.929233] VMEM_VDD_2.8V: Failed to create debugfs directory
> [ 0.935810] TSP_AVDD_3.3V: 3300 mV
> [ 0.940670] TSP_VDD_1.8V: 1800 mV
> [ 0.947112] LCD_VCC_3.3V: 2800 mV
> [ 0.951896] MOTOR_VCC_3.0V: 3000 mV
> [ 0.957637] vdd_mif: 850 <--> 1100 mV at 1000 mV
> [ 0.964138] vdd_arm: 850 <--> 1500 mV at 1100 mV
> [ 0.970659] vdd_int: 850 <--> 1150 mV at 1000 mV
> [ 0.977176] vdd_g3d: 850 <--> 1150 mV at 1000 mV
> [ 0.983693] VMEM_1.2V_AP: 1200 mV
> [ 0.988888] VCC_SUB_1.35V: 1350 mV
> [ 0.994170] VCC_SUB_2.0V: 2000 mV
> [ 0.999704] VMEM_VDDF_3.0V: 2850 mV
> [ 1.004672] CAM_ISP_CORE_1.2V: 1000 <--> 1200 mV at 1200 mV
> [ 1.011624] s3c-i2c 138d0000.i2c: i2c-7: S3C I2C adapter
> [ 1.017264] media: Linux media interface: v0.10
> [ 1.022084] Linux video capture interface: v2.00
> [ 1.034087] Switched to clocksource mct-frc
> [ 1.065452] NET: Registered protocol family 2
> [ 1.070751] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
> [ 1.077876] TCP bind hash table entries: 8192 (order: 5, 163840 bytes)
> [ 1.084607] TCP: Hash tables configured (established 8192 bind 8192)
> [ 1.091055] TCP: reno registered
> [ 1.094259] UDP hash table entries: 512 (order: 2, 24576 bytes)
> [ 1.100265] UDP-Lite hash table entries: 512 (order: 2, 24576 bytes)
> [ 1.106941] NET: Registered protocol family 1
> [ 1.114343] futex hash table entries: 1024 (order: 4, 65536 bytes)
> [ 1.136661] romfs: ROMFS MTD (C) 2007 Red Hat, Inc.
> [ 1.141805] msgmni has been set to 1488
> [ 1.146841] bounce: pool size: 64 pages
> [ 1.150668] io scheduler noop registered
> [ 1.154646] io scheduler deadline registered
> [ 1.159350] io scheduler cfq registered (default)
> [ 1.174939] dma-pl330 12680000.pdma: Loaded driver for PL330 DMAC-1315632
> [ 1.181696] dma-pl330 12680000.pdma: DBUFF-32x4bytes Num_Chans-8 Num_Peri-32 Num_Events-32
> [ 1.197223] dma-pl330 12690000.pdma: Loaded driver for PL330 DMAC-1315632
> [ 1.204000] dma-pl330 12690000.pdma: DBUFF-32x4bytes Num_Chans-8 Num_Peri-32 Num_Events-32
> [ 1.214521] dma-pl330 12850000.mdma: Loaded driver for PL330 DMAC-1315632
> [ 1.221275] dma-pl330 12850000.mdma: DBUFF-64x8bytes Num_Chans-8 Num_Peri-1 Num_Events-32
> [ 1.397474] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
> [ 1.406862] 13800000.serial: ttySAC0 at MMIO 0x13800000 (irq = 84, base_baud = 0) is a S3C6400/10
> [ 1.416444] 13810000.serial: ttySAC1 at MMIO 0x13810000 (irq = 85, base_baud = 0) is a S3C6400/10
> [ 1.426041] 13820000.serial: ttySAC2 at MMIO 0x13820000 (irq = 86, base_baud = 0) is a S3C6400/10
> [ 1.434949] console [tt[SAC2] enabled
> 1.434949] console [ttySAC2] enabled
> [ 1.442166] bootconsole [early[on0] disabled
> 1.442166] bootconsole [earlycon0] disabled
> [ 1.451388] 13830000.serial: ttySAC3 at MMIO 0x13830000 (irq = 87, base_baud = 0) is a S3C6400/10
> [ 1.461017] [drm] Initialized drm 1.1.0 20060810
> [ 1.467495] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
> [ 1.472686] [drm] No driver support for vblank timestamp query.
> [ 1.478649] exynos-drm exynos-drm: bound 11c00000.fimd (ops fimd_component_ops)
> [ 1.486503] exynos-drm exynos-drm: bound 11c80000.dsi (ops exynos_dsi_component_ops)
> [ 1.493678] [drm] Initialized exynos 1.0.0 20110530 on minor 0
> [ 1.499943] panel_s6e8aa0 11c80000.dsi.0: GPIO lookup for consumer reset
> [ 1.506120] panel_s6e8aa0 11c80000.dsi.0: using device tree for GPIO lookup
> [ 1.513071] of_get_named_gpiod_flags exited with status 0
> [ 1.721532] panel_s6e8aa0 11c80000.dsi.0: ID: 0xa2, 0x60, 0x90
> [ 1.894152] [drm:drm_calc_timestamping_constants] *ERROR* crtc 12: Can't calculate constants, dotclock = 0!
> [ 1.927913] Console: switching to colour frame buffer device 102x91
> [ 1.980431] exynos-drm exynos-drm: fb0: frame buffer device
> [ 1.986071] exynos-drm exynos-drm: registered panic notifier
> [ 2.019291] brd: module loaded
> [ 2.028936] loop: module loaded
> [ 2.031779] s3c64xx-spi 13930000.spi: spi bus clock parent not specified, using clock at index 0 as parent
> [ 2.040311] s3c64xx-spi 13930000.spi: number of chip select lines not specified, assuming 1 chip select line
> [ 2.052146] usbcore: registered new interface driver asix
> [ 2.056299] usbcore: registered new interface driver ax88179_178a
> [ 2.062390] usbcore: registered new interface driver cdc_ether
> [ 2.068182] usbcore: registered new interface driver smsc75xx
> [ 2.073907] usbcore: registered new interface driver smsc95xx
> [ 2.079624] usbcore: registered new interface driver net1080
> [ 2.085248] usbcore: registered new interface driver cdc_subset
> [ 2.091127] usbcore: registered new interface driver zaurus
> [ 2.096769] usbcore: registered new interface driver cdc_ncm
> [ 2.103145] s3c-hsotg 12480000.hsotg: regs f04c0000, irq 103
> [ 2.109441] s3c-hsotg 12480000.hsotg: EPs:15
> [ 2.112241] s3c-hsotg 12480000.hsotg: dedicated fifos
> [ 2.120254] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
> [ 2.125422] ehci-exynos: EHCI EXYNOS driver
> [ 2.130271] usbcore: registered new interface driver usb-storage
> [ 2.136516] mousedev: PS/2 mouse device common for all mice
> [ 2.144388] ERROR: could not get clock /i2c@13860000/s5c73m3@3c:cis_extclk(0)
> [ 2.150125] i2c 0-003c: Driver S5C73M3 requests probe deferral
> [ 2.156957] s5p-mipi-csis 11880000.csis: lanes: 4, hs_settle: 12, wclk: 0, freq: 176000000
> [ 2.164836] s5p-mipi-csis 11890000.csis: lanes: 1, hs_settle: 18, wclk: 1, freq: 160000000
> [ 2.175582] ERROR: could not get clock /camera/fimc-is@12000000/i2c-isp@12140000/s5k6a3@10:extclk(0)
> [ 2.183306] i2c 1-0010: Driver S5K6A3 requests probe deferral
> [ 2.191900] exynos4-fimc-is 12000000.fimc-is: Direct firmware load failed with error -2
> [ 2.198501] exynos4-fimc-is 12000000.fimc-is: Falling back to user helper
> [ 2.198865] isp-power-domain: Power-off latency exceeded, new value 285125 ns
> [ 2.213436] s5p-fimc-md: Registered fimc.0.m2m as /dev/video0
> [ 2.218521] s5p-fimc-md: Registered fimc.0.capture as /dev/video1
> [ 2.224563] s5p-fimc-md: Registered fimc.1.m2m as /dev/video2
> [ 2.230371] s5p-fimc-md: Registered fimc.1.capture as /dev/video3
> [ 2.236463] s5p-fimc-md: Registered fimc-lite.0.capture as /dev/video4
> [ 2.242875] s5p-fimc-md: Registered fimc-lite.1.capture as /dev/video5
> [ 2.249499] s5p-fimc-md: Registered fimc-is-isp.capture as /dev/video6
> [ 2.255932] cam-power-domain: Power-off latency exceeded, new value 271875 ns
> [ 2.264529] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@xxxxxxxxxx
> [ 2.275629] sdhci: Secure Digital Host Controller Interface driver
> [ 2.280418] sdhci: Copyright(c) Pierre Ossman
> [ 2.285026] Synopsys Designware Multimedia Card Interface Driver
> [ 2.291612] dwmmc_exynos 12550000.mmc: Using internal DMA controller.
> [ 2.297169] dwmmc_exynos 12550000.mmc: Version ID is 240a
> [ 2.302814] dwmmc_exynos 12550000.mmc: DW MMC controller at irq 109, 32 bit host data width, 128 deep fifo
> [ 2.312220] of_get_named_gpiod_flags: can't parse gpios property of node '/mmc@12550000[0]'
> [ 2.349217] dwmmc_exynos 12550000.mmc: 1 slots initialized
> [ 2.355245] usbcore: registered new interface driver usbhid
> [ 2.359407] usbhid: USB HID core driver
> [ 2.363404] TCP: cubic registered
> [ 2.366559] NET: Registered protocol family 17
> [ 2.371013] NET: Registered protocol family 15
> [ 2.375637] Registering SWP/SWPB emulation handler
> [ 2.380170] gps-alive-power-domain: Power-off latency exceeded, new value 4634500 ns
> [ 2.387932] gps-power-domain: Power-off latency exceeded, new value 12171083 ns
> [ 2.389617] of_get_named_gpiod_flags exited with status 0
> [ 2.389637] of_get_named_gpiod_flags exited with status 0
> [ 2.390364] S5C73M3: S5C73M3 SPI probed successfully
> [ 2.411122] tv-power-domain: Power-off latency exceeded, new value 178625 ns
> [ 2.417923] g3d-power-domain: Power-off latency exceeded, new value 6944459 ns
> [ 2.425415] mfc-power-domain: Power-off latency exceeded, new value 179542 ns
> [ 2.436992] cam-power-domain: Power-on latency exceeded, new value 434833 ns
> [ 2.455453] S5C73M3: Sensor type: CML0801-M080, FW version: ZHFJ02
> [ 2.460833] cam-power-domain: Power-off latency exceeded, new value 274084 ns
> [ 2.471060] s5p-fimc-md: Registered sensor subdevice: S5C73M3-OIF (0)
> [ 2.476069] S5C73M3: s5c73m3_probe: completed successfully
> [ 2.481721] of_get_named_gpiod_flags exited with status 0
> [ 2.487347] s5p-fimc-md: Registered sensor subdevice: S5K6A3 1-0010 (1)
> [ 2.493544] s5p-fimc-md: created link [S5C73M3-OIF] => [s5p-mipi-csis.0]
> [ 2.500212] s5p-fimc-md: created link [S5K6A3 1-0010] => [s5p-mipi-csis.1]
> [ 2.507065] s5p-fimc-md: created link [s5p-mipi-csis.0] => [FIMC.0]
> [ 2.513313] s5p-fimc-md: created link [s5p-mipi-csis.0] -> [FIMC.1]
> [ 2.513390] mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 52000000Hz, actual 50000000HZ div = 0)
> [ 2.529361] s5p-fimc-md: created link [s5p-mipi-csis.0] -> [FIMC-LITE.0]
> [ 2.536009] s5p-fimc-md: created link [s5p-mipi-csis.0] -> [FIMC-LITE.1]
> [ 2.542689] s5p-fimc-md: created link [s5p-mipi-csis.1] -> [FIMC-LITE.0]
> [ 2.542755] mmc_host mmc0: Bus speed (slot 0) = 100000000Hz (slot req 52000000Hz, actual 50000000HZ div = 1)
> [ 2.542976] mmc0: new DDR MMC card at address 0001
> [ 2.549471] mmcblk0: mmc0:0001 VTU00M 14.6 GiB
> [ 2.549691] mmcblk0boot0: mmc0:0001 VTU00M partition 1 2.00 MiB
> [ 2.549917] mmcblk0boot1: mmc0:0001 VTU00M partition 2 2.00 MiB
> [ 2.550125] mmcblk0rpmb: mmc0:0001 VTU00M partition 3 128 KiB
> [ 2.555724] mmcblk0: p1 p2 p3 p4 p5 p6 p7
> [ 2.561000] mmcblk0boot1: unknown partition table
> [ 2.562557] mmcblk0boot0: unknown partition table
> [ 2.599618] s5p-fimc-md: created link [s5p-mipi-csis.1] -> [FIMC-LITE.1]
> [ 2.610369] of_get_named_gpiod_flags exited with status 0
> [ 2.614413] of_get_named_gpiod_flags exited with status 0
> [ 2.619804] of_get_named_gpiod_flags exited with status 0
> [ 2.625115] of_get_named_gpiod_flags exited with status 0
> [ 2.630533] gpio-239 (volume down): gpiod_set_debounce: missing set() or set_debounce() operations
> [ 2.639541] gpio-230 (volume up): gpiod_set_debounce: missing set() or set_debounce() operations
> [ 2.648314] gpio-235 (power): gpiod_set_debounce: missing set() or set_debounce() operations
> [ 2.656718] gpio-213 (ok): gpiod_set_debounce: missing set() or set_debounce() operations
> [ 2.665165] input: gpio-keys as /devices/gpio-keys/input/input0
> [ 2.671295] drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
> [ 2.693343] vdd_g3d: disabling
> [ 2.698346] VDDQ_PRE_1.8V: disabling
> [ 2.703375] VHSIC_1.8V: disabling
> [ 2.708141] LED_A_3.0V: disabling
> [ 2.710069] CAM_AF: disabling
> [ 2.712939] CAM_SENSOR_A: disabling
> [ 62.334649] exynos4-fimc-is 12000000.fimc-is: firmware request failed
> [ 240.679135] INFO: task swapper/0:1 blocked for more than 120 seconds.
> [ 240.684143] Not tainted 3.16.0-rc2-next-20140625-00007-g993e726d-dirty #905
> [ 240.691626] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 240.699408] swapper/0 D c0418014 0 1 0 0x00000000
> [ 240.705765] [<c0418014>] (__schedule) from [<c0418734>] (schedule_preempt_disabled+0x14/0x20)
> [ 240.714267] [<c0418734>] (schedule_preempt_disabled) from [<c041ac5c>] (__mutex_lock_slowpath+0x1a0/0x3e4)
> [ 240.723892] [<c041ac5c>] (__mutex_lock_slowpath) from [<c041aeac>] (mutex_lock+0xc/0x24)
> [ 240.732022] [<c041aeac>] (mutex_lock) from [<c0278170>] (regmap_read+0x30/0x60)
> [ 240.739280] [<c0278170>] (regmap_read) from [<c036d51c>] (max77686_clk_is_prepared+0x20/0x3c)
> [ 240.747768] [<c036d51c>] (max77686_clk_is_prepared) from [<c036a59c>] (clk_unprepare_unused_subtree+0x64/0x98)
> [ 240.757745] [<c036a59c>] (clk_unprepare_unused_subtree) from [<c036a654>] (clk_disable_unused+0x84/0xd8)
> [ 240.767205] [<c036a654>] (clk_disable_unused) from [<c0008990>] (do_one_initcall+0x8c/0x1c4)
> [ 240.775634] [<c0008990>] (do_one_initcall) from [<c05b5cf0>] (kernel_init_freeable+0x138/0x1d8)
> [ 240.784318] [<c05b5cf0>] (kernel_init_freeable) from [<c04132d0>] (kernel_init+0x8/0xf0)
> [ 240.792382] [<c04132d0>] (kernel_init) from [<c000e678>] (ret_from_fork+0x14/0x3c)
> [ 240.799923] INFO: task kworker/0:0:4 blocked for more than 120 seconds.
> [ 240.806513] Not tainted 3.16.0-rc2-next-20140625-00007-g993e726d-dirty #905
> [ 240.813975] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 240.821787] kworker/0:0 D c0418014 0 4 2 0x00000000
> [ 240.828118] Workqueue: events od_dbs_timer
> [ 240.832198] [<c0418014>] (__schedule) from [<c0418734>] (schedule_preempt_disabled+0x14/0x20)
> [ 240.840728] [<c0418734>] (schedule_preempt_disabled) from [<c041ac5c>] (__mutex_lock_slowpath+0x1a0/0x3e4)
> [ 240.850357] [<c041ac5c>] (__mutex_lock_slowpath) from [<c041aeac>] (mutex_lock+0xc/0x24)
> [ 240.858430] [<c041aeac>] (mutex_lock) from [<c03692c0>] (clk_prepare_lock+0x88/0xfc)
> [ 240.866159] [<c03692c0>] (clk_prepare_lock) from [<c036ac80>] (clk_unprepare+0x18/0x28)
> [ 240.874154] [<c036ac80>] (clk_unprepare) from [<c02f67ac>] (s3c24xx_i2c_xfer+0x18c/0x40c)
> [ 240.882305] [<c02f67ac>] (s3c24xx_i2c_xfer) from [<c02f127c>] (__i2c_transfer+0x78/0x90)
> [ 240.890373] [<c02f127c>] (__i2c_transfer) from [<c02f2560>] (i2c_transfer+0xa0/0xd8)
> [ 240.898096] [<c02f2560>] (i2c_transfer) from [<c027c6d4>] (regmap_i2c_read+0x48/0x64)
> [ 240.905916] [<c027c6d4>] (regmap_i2c_read) from [<c0278648>] (_regmap_raw_read+0x98/0xf4)
> [ 240.914118] [<c0278648>] (_regmap_raw_read) from [<c02786c8>] (_regmap_bus_read+0x24/0x5c)
> [ 240.922323] [<c02786c8>] (_regmap_bus_read) from [<c02780c8>] (_regmap_read+0x6c/0xe4)
> [ 240.930266] [<c02780c8>] (_regmap_read) from [<c0278180>] (regmap_read+0x40/0x60)
> [ 240.937693] [<c0278180>] (regmap_read) from [<c020a218>] (regulator_is_enabled_regmap+0x20/0x9c)
> [ 240.946463] [<c020a218>] (regulator_is_enabled_regmap) from [<c0206b14>] (_regulator_is_enabled.part.16+0x1c/0x28)
> [ 240.956785] [<c0206b14>] (_regulator_is_enabled.part.16) from [<c020705c>] (_regulator_do_set_voltage+0x2d0/0x348)
> [ 240.967105] [<c020705c>] (_regulator_do_set_voltage) from [<c0207184>] (regulator_set_voltage+0xb0/0x13c)
> [ 240.976650] [<c0207184>] (regulator_set_voltage) from [<c0337250>] (exynos_target+0x268/0x2d4)
> [ 240.985248] [<c0337250>] (exynos_target) from [<c0331680>] (__cpufreq_driver_target+0x158/0x294)
> [ 240.994020] [<c0331680>] (__cpufreq_driver_target) from [<c0336750>] (dbs_check_cpu+0x1a4/0x1e4)
> [ 241.002782] [<c0336750>] (dbs_check_cpu) from [<c0335390>] (od_dbs_timer+0x78/0x130)
> [ 241.010512] [<c0335390>] (od_dbs_timer) from [<c0032854>] (process_one_work+0x11c/0x35c)
> [ 241.018580] [<c0032854>] (process_one_work) from [<c00330c8>] (worker_thread+0x4c/0x568)
> [ 241.026649] [<c00330c8>] (worker_thread) from [<c003876c>] (kthread+0xd8/0xf0)
> [ 241.033856] [<c003876c>] (kthread) from [<c000e678>] (ret_from_fork+0x14/0x3c)
> [ 241.041060] INFO: task kworker/1:1:444 blocked for more than 120 seconds.
> [ 241.047818] Not tainted 3.16.0-rc2-next-20140625-00007-g993e726d-dirty #905
> [ 241.055278] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 241.063090] kworker/1:1 D c0418014 0 444 2 0x00000000
> [ 241.069435] Workqueue: events od_dbs_timer
> [ 241.073501] [<c0418014>] (__schedule) from [<c0418734>] (schedule_preempt_disabled+0x14/0x20)
> [ 241.082034] [<c0418734>] (schedule_preempt_disabled) from [<c041ac5c>] (__mutex_lock_slowpath+0x1a0/0x3e4)
> [ 241.091663] [<c041ac5c>] (__mutex_lock_slowpath) from [<c041aeac>] (mutex_lock+0xc/0x24)
> [ 241.099736] [<c041aeac>] (mutex_lock) from [<c033535c>] (od_dbs_timer+0x44/0x130)
> [ 241.107203] [<c033535c>] (od_dbs_timer) from [<c0032854>] (process_one_work+0x11c/0x35c)
> [ 241.115274] [<c0032854>] (process_one_work) from [<c00330c8>] (worker_thread+0x4c/0x568)
> [ 241.123342] [<c00330c8>] (worker_thread) from [<c003876c>] (kthread+0xd8/0xf0)
> [ 241.130602] [<c003876c>] (kthread) from [<c000e678>] (ret_from_fork+0x14/0x3c)
> [ 241.137758] INFO: task kworker/3:1:1154 blocked for more than 120 seconds.
> [ 241.144604] Not tainted 3.16.0-rc2-next-20140625-00007-g993e726d-dirty #905
> [ 241.152061] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 241.159874] kworker/3:1 D c0418014 0 1154 2 0x00000000
> [ 241.166221] Workqueue: events od_dbs_timer
> [ 241.170283] [<c0418014>] (__schedule) from [<c0418734>] (schedule_preempt_disabled+0x14/0x20)
> [ 241.178811] [<c0418734>] (schedule_preempt_disabled) from [<c041ac5c>] (__mutex_lock_slowpath+0x1a0/0x3e4)
> [ 241.188447] [<c041ac5c>] (__mutex_lock_slowpath) from [<c041aeac>] (mutex_lock+0xc/0x24)
> [ 241.196519] [<c041aeac>] (mutex_lock) from [<c033535c>] (od_dbs_timer+0x44/0x130)
> [ 241.203986] [<c033535c>] (od_dbs_timer) from [<c0032854>] (process_one_work+0x11c/0x35c)
> [ 241.212065] [<c0032854>] (process_one_work) from [<c00330c8>] (worker_thread+0x4c/0x568)
> [ 241.220131] [<c00330c8>] (worker_thread) from [<c003876c>] (kthread+0xd8/0xf0)
> [ 241.227331] [<c003876c>] (kthread) from [<c000e678>] (ret_from_fork+0x14/0x3c)
> [ 241.234531] INFO: task kworker/2:1:1273 blocked for more than 120 seconds.
> [ 241.241381] Not tainted 3.16.0-rc2-next-20140625-00007-g993e726d-dirty #905
> [ 241.248843] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 241.256654] kworker/2:1 D c0418014 0 1273 2 0x00000000
> [ 241.262978] Workqueue: events od_dbs_timer
> [ 241.267063] [<c0418014>] (__schedule) from [<c0418734>] (schedule_preempt_disabled+0x14/0x20)
> [ 241.275595] [<c0418734>] (schedule_preempt_disabled) from [<c041ac5c>] (__mutex_lock_slowpath+0x1a0/0x3e4)
> [ 241.285227] [<c041ac5c>] (__mutex_lock_slowpath) from [<c041aeac>] (mutex_lock+0xc/0x24)
> [ 241.293298] [<c041aeac>] (mutex_lock) from [<c033535c>] (od_dbs_timer+0x44/0x130)
> [ 241.300765] [<c033535c>] (od_dbs_timer) from [<c0032854>] (process_one_work+0x11c/0x35c)
> [ 241.308834] [<c0032854>] (process_one_work) from [<c00330c8>] (worker_thread+0x4c/0x568)
> [ 241.316905] [<c00330c8>] (worker_thread) from [<c003876c>] (kthread+0xd8/0xf0)
> [ 241.324111] [<c003876c>] (kthread) from [<c000e678>] (ret_from_fork+0x14/0x3c)

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