H
On 2 June 2015 at 16:17, Michal Suchanek <hramrach@xxxxxxxxx> wrote:
> On 2 June 2015 at 15:08, Vinod Koul <vinod.koul@xxxxxxxxx> wrote:
>> On Sat, May 30, 2015 at 09:37:07PM +0200, Michal Suchanek wrote:
>>> Hello,
>>>
>>> I was trying to read the SPI NOR flash and found that the pl330
>>> controller dma mysteriously fails.
>>
>> Adding Robert,
>>
>>>
>>> There is the problem that the 256 bytes of dma program buffer does not
>>> suffice for the whole of 4M of the flash memory so all of it cannot be
>>> possibly transferred in one go with the pl330 driver as is now.
>>>
>>> However, the practical limit is much smaller. At 1MHz or 40MHz the
>>> maximum transfer size that ever finishes is 64k. At 133MHz which is
>>> the rated flash memory clock the maximum transfer size that finishes
>>> is 128 bytes (only tried power of 2).
>>>
>>> There is no obvious issue with the DMA program. 128k happens to be the
>>> smallest size that requires that the burst instruction is repeated in
>>> the cycle and also happens to be the smallest size that fails for any
>>> speed I tried.
>>>
>>> Is there some obvious fix or should I just give up on transferring
>>> more than 64k and make the driver truncate any larger transfers?
>> Well dma controllers cannot transfer any size, the controllers do have
>> limitation on maximum transfer per block. So to transfer more data you need
>> to create descriptor with multiple segments (or driver should split that but
>> not done usually) and worst case multiple transfers.
>
> Hello,
>
> Thanks for your input.
>
> As I understand the pl330 it transfers data according to a program
> executed on the controller.
> The program itself uses DMALDPS/DMASTA instructions which transfers
> data one byte at a time and there are up to 2 loops with 8bit counter
> DMALP.
>
> So the theoretical limit by the program buffer size (256 bytes) is
> about 2Mbytes.
>
> However, the program for transferring 128k (which happens to have two
> DMALDPS/DMASTA instructions in the cycle as opposed to the one
> instruction for transferring 64k) locks up and never (within 10x the
> expected time it should take to complete the transfer) reaches DMASEV
> to signal completion of the DMA transfer. Also subsequent commands on
> on the flash fail probably due to stale data in some FIFO - this can
> be resolved by sending lots of nops to the flash.
>
> There are two problems with this - it is not known in advance what
> amount of data can be transferred without pl330 locking up. It is 64k
> at 40MHz spi and 128bytes at 133MHz spi on my system.
>
> The other problem is that even if the limitation was known there is no
> way to let the upper layer know other than transferring less data than
> requested.
>
> It is also possible to orchestrate many small transactions with DMASEV
> signalling some pl330 function to program new transfer rather than the
> user code that waits for the transfer to finish.
>>> [ 60.780206] m25p80 spi1.0: from 0x00000000, len 131072
>>> [ 60.780291] s3c64xx_spi_transfer_one 12d30000.spi spi1 spi1.0 xfer
>>> bpw 8 speed 40000000
>>> [ 60.780297] s3c64xx_spi_transfer_one 12d30000.spi spi1 spi1.0 not using dma
>>> [ 60.780312] s3c64xx_spi_transfer_one 12d30000.spi spi1 spi1.0 xfer
>>> bpw 8 speed 40000000
>>> [ 60.780316] s3c64xx_spi_transfer_one 12d30000.spi spi1 spi1.0 using dma
>>> [ 60.780327] bc041000: DMAMOV CCR 0x804200
>>> [ 60.780333] bc041006: DMAMOV SAR 0x12d3001c
>>> [ 60.780338] bc04100c: DMAMOV DAR 0x68020000
>>> [ 60.780344] bc041012: DMALP_0 255
>>> [ 60.780349] bc041014: DMALP_1 255
>>> [ 60.780355] bc041016: DMAWFPS 4
>>> [ 60.780360] bc041018: DMALDPS 4
>>> [ 60.780365] bc04101a: DMASTA
>>> [ 60.780370] bc04101b: DMAFLUSHP 4
>>> [ 60.780375] bc04101d: DMAWFPS 4
>>> [ 60.780380] bc04101f: DMALDPS 4
>>> [ 60.780385] bc041021: DMASTA
>>> [ 60.780390] bc041022: DMAFLUSHP 4
>>> [ 60.780395] bc041024: DMALPENDA_1 bjmpto_e
>>> [ 60.780401] bc041026: DMALPENDA_0 bjmpto_12
>>> [ 60.780406] bc041028: DMASEV 0
>>> [ 60.780411] bc04102a: DMAEND
>>> [ 60.780423] wait_for_dma 12d30000.spi spi1 (null) waiting for 72ms
>>> transferring 131072bytes@40000000Hz
>>> [ 60.903505] wait_for_dma 12d30000.spi spi1 (null) waited 125 ms
>>> [ 60.903518] m25p80 spi1.0: I/O Error: rx-1 tx-0 res:rx-f tx-p len-131072
>>> [ 60.903530] m25p80 spi1.0: SPI transfer failed: -5
>>> [ 60.903590] spi_master spi1: failed to transfer one message from queue
Hello,
I added more debug prints (and nops in the middle of the dma program
just in case) and clearly the event that is supposed to be produced by
the DMASEV in this program is never delivered for program of this
length. The shorter program with only one DMALDPS in the loop works.
Attaching a dmesg excerpt.
It has been pointed out that Catalin Marinas might know of some source
of information on this dma controller so adding to CC.
Thanks
Michal
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.1.0-rc7-00343-g81371ef (hramrach@iscsi) (gcc version 4.9.2 ( 4.9.2-10) ) #35 SMP PREEMPT Fri Jun 12 12:06:15 CEST 2015
[ 0.000000] CPU: ARMv7 Processor [410fc0f4] revision 4 (ARMv7), cr=10c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[ 0.000000] Machine model: Google Snow
[ 0.000000] cma: Reserved 64 MiB at 0xbc000000
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] Samsung CPU ID: 0x43520010
[ 0.000000] On node 0 totalpages: 524288
[ 0.000000] free_area_init_node: node 0, pgdat c09dc580, node_mem_map ee7f7000
[ 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: 329728 pages, LIFO batch:31
[ 0.000000] PERCPU: Embedded 12 pages/cpu @ee79e000 s16448 r8192 d24512 u49152
[ 0.000000] pcpu-alloc: s16448 r8192 d24512 u49152 alloc=12*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 522768
[ 0.000000] Kernel command line: root=/dev/mmcblk1p5 rw console=tty0 earlyprintk debug=1 initcall_debug rootwait dyndbg=\"file spi-s3* +p ; file spi-nor.c +p ; file spi* +p ; file m25p80.c +p \"
[ 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: 2003500K/2097152K available (6614K kernel code, 338K rwdata, 2780K rodata, 436K init, 307K bss, 28116K reserved, 65536K cma-reserved, 1253376K highmem)
[ 0.000000] Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
vmalloc : 0xf0000000 - 0xff000000 ( 240 MB)
lowmem : 0xc0000000 - 0xef800000 ( 760 MB)
pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
modules : 0xbf000000 - 0xbfe00000 ( 14 MB)
.text : 0xc0008000 - 0xc0934d8c (9396 kB)
.init : 0xc0935000 - 0xc09a2000 ( 436 kB)
.data : 0xc09a2000 - 0xc09f6b38 ( 339 kB)
.bss : 0xc09f9000 - 0xc0a45ff4 ( 308 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000000] Preemptible hierarchical RCU implementation.
[ 0.000000] Additional per-CPU info printed with stalls.
[ 0.000000] RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=2.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000000] GIC physical location is 0x10481000
[ 0.000000] L2C: failed to init: -19
[ 0.000000] Exynos5250: clock setup completed, armclk=1700000000
[ 0.000000] Architected cp15 timer(s) running at 24.00MHz (virt).
[ 0.000000] clocksource arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 440795202592 ns
[ 0.000002] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
[ 0.000009] Switching to timer-based delay loop, resolution 41ns
[ 0.000203] Ignoring duplicate/late registration of read_current_timer delay
[ 0.000211] clocksource mct-frc: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[ 0.000219] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns
[ 0.000474] Console: colour dummy device 80x30
[ 0.000826] console [tty0] enabled
[ 0.000841] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=120000)
[ 0.000863] pid_max: default: 32768 minimum: 301
[ 0.000926] Security Framework initialized
[ 0.000969] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000983] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.001335] CPU: Testing write buffer coherency: ok
[ 0.001475] CPU0: update cpu_capacity 1024
[ 0.001488] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.001651] Setting up static identity map for 0x40008280 - 0x400082d8
[ 0.021513] dynamic_debug:ddebug_parse_query: unknown keyword "\"file"
[ 0.021528] dynamic_debug:ddebug_exec_query: query parse failed
[ 0.023088] dynamic_debug:ddebug_parse_flags: bad flag-op \, at start of \"
[ 0.023100] dynamic_debug:ddebug_exec_query: flags parse failed
[ 0.040134] CPU1: update cpu_capacity 1024
[ 0.040137] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.040184] Brought up 2 CPUs
[ 0.040212] SMP: Total of 2 processors activated (96.00 BogoMIPS).
[ 0.040223] CPU: All CPU(s) started in SVC mode.
[ 0.040506] devtmpfs: initialized
[ 0.053562] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
[ 0.054086] clocksource jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302231375000 ns
[ 0.180268] dma-pl330 121a0000.pdma: Loaded driver for PL330 DMAC-241330
[ 0.180286] dma-pl330 121a0000.pdma: DBUFF-32x4bytes Num_Chans-8 Num_Peri-32 Num_Events-32
[ 0.182619] dma-pl330 121b0000.pdma: Loaded driver for PL330 DMAC-241330
[ 0.182638] dma-pl330 121b0000.pdma: DBUFF-32x4bytes Num_Chans-8 Num_Peri-32 Num_Events-32
[ 0.183287] dma-pl330 10800000.mdma: Loaded driver for PL330 DMAC-241330
[ 0.183304] dma-pl330 10800000.mdma: DBUFF-64x8bytes Num_Chans-8 Num_Peri-1 Num_Events-32
[ 0.183940] dma-pl330 11c10000.mdma: Loaded driver for PL330 DMAC-241330
[ 0.183956] dma-pl330 11c10000.mdma: DBUFF-64x8bytes Num_Chans-8 Num_Peri-1 Num_Events-32
[ 0.242508] of_get_named_gpiod_flags: parsed 'cs-gpios' property of node '/spi@12d30000[0]' - status (0)
[ 0.242627] s3c64xx-spi 12d30000.spi: registered master spi1
[ 0.242731] spi spi1.0: setup mode 0, 8 bits/w, 40000000 Hz max --> 0
[ 0.242903] spi_master spi1: s3c64xx_spi_config: clk_from_cmu 1 src_clk sclk_spi1 mode bpw 8
[ 0.242951] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 0.242968] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: not using dma
[ 0.242989] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 0.243005] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: not using dma
[ 0.243037] m25p80 spi1.0: gd25lq32c (4096 Kbytes)
[ 0.243052] m25p80 spi1.0: mtd .name = spi1.0, .size = 0x400000 (4MiB), .erasesize = 0x00001000 (4KiB) .numeraseregions = 0
[ 0.243071] m25p80 spi1.0: Using maximum transfer length 131072
[ 0.243087] No valid partition found on /spi@12d30000/m25p80@0
[ 0.243393] s3c64xx-spi 12d30000.spi: registered child spi1.0
[ 0.243410] s3c64xx-spi 12d30000.spi: Samsung SoC SPI Driver loaded for Bus SPI-1 with 1 Slaves attached
[ 0.243429] s3c64xx-spi 12d30000.spi: IOmem=[[mem 0x12d30000-0x12d300ff]] DMA=[Rx-0, Tx-0]
[ 0.841081] max77686-rtc max77686-rtc: max77686_rtc_probe
[ 0.940867] max77686-rtc max77686-rtc: rtc core: registered max77686-rtc as rtc0
[ 0.941451] s3c-rtc 101e0000.rtc: failed to find rtc source clock
[ 0.941706] i2c /dev entries driver
[ 0.943177] of_get_named_gpiod_flags: parsed 'our-claim-gpio' property of node '/i2c-arbitrator[0]' - status (0)
[ 0.943210] of_get_named_gpiod_flags: parsed 'their-claim-gpios' property of node '/i2c-arbitrator[0]' - status (0)
[ 0.943237] of_get_named_gpiod_flags: can't parse 'their-claim-gpios' property of node '/i2c-arbitrator[1]'
[ 0.944166] input: cros-ec-i2c as /devices/platform/12ca0000.i2c/i2c-4/i2c-104/104-001e/cros-ec-keyb.1/input/input1
[ 0.944508] cros-ec-i2c-tunnel cros-ec-i2c-tunnel.2: Couldn't read remote-bus property
[ 0.944533] cros-ec-i2c-tunnel: probe of cros-ec-i2c-tunnel.2 failed with error -22
[ 0.944650] cros-ec-i2c 104-001e: Chrome EC device registered
[ 0.944825] tps65090 104-0048: No cache defaults, reading back from HW
[ 0.948977] of_get_named_gpiod_flags: can't parse 'dcdc-ext-control-gpios' property of node '/i2c-arbitrator/i2c@0/power-regulator[0]'
[ 0.948999] of_get_named_gpiod_flags: can't parse 'dcdc-ext-control-gpios' property of node '/i2c-arbitrator/i2c@0/power-regulator[0]'
[ 0.949019] of_get_named_gpiod_flags: can't parse 'dcdc-ext-control-gpios' property of node '/i2c-arbitrator/i2c@0/power-regulator[0]'
[ 0.967331] i2c i2c-4: Added multiplexed i2c bus 104
[ 1.012296] sbs-battery 104-000b: sbs-battery: battery gas gauge device registered
[ 1.017622] thermal thermal_zone0: failed to read out thermal zone (-22)
[ 1.017651] 10060000.tmu supply vtmu not found, using dummy regulator
[ 1.018394] s3c2410-wdt 101d0000.watchdog: watchdog inactive, reset disabled, irq disabled
[ 1.181504] max98095 7-0011: Hardware revision: C
[ 1.189962] max98095 7-0011: ASoC: mux Linein Mux has no paths
[ 1.189982] max98095 7-0011: ASoC: mux External MIC has no paths
[ 1.199419] nxp,ptn3460 7-0020: GPIO lookup for consumer powerdown
[ 1.199431] nxp,ptn3460 7-0020: using device tree for GPIO lookup
[ 1.199448] of_get_named_gpiod_flags: parsed 'powerdown-gpios' property of node '/i2c@12CD0000/lvds-bridge@20[0]' - status (0)
[ 1.199470] no flags found for powerdown
[ 1.199483] nxp,ptn3460 7-0020: GPIO lookup for consumer reset
[ 1.199495] nxp,ptn3460 7-0020: using device tree for GPIO lookup
[ 1.199509] of_get_named_gpiod_flags: parsed 'reset-gpios' property of node '/i2c@12CD0000/lvds-bridge@20[0]' - status (0)
[ 1.199530] no flags found for reset
[ 1.199854] s3c-rtc 101e0000.rtc: rtc disabled, re-enabling
[ 1.199913] s3c-rtc 101e0000.rtc: warning: invalid RTC value so initializing it
[ 1.200104] s3c-rtc 101e0000.rtc: rtc core: registered s3c as rtc1
[ 1.570924] of_get_named_gpiod_flags: parsed 'gpios' property of node '/gpio-keys/power[0]' - status (0)
[ 1.571007] of_get_named_gpiod_flags: parsed 'gpios' property of node '/gpio-keys/lid-switch[0]' - status (0)
[ 1.571101] gpio-143 (Power): gpiod_set_debounce: missing set() or set_debounce() operations
[ 1.571211] gpio-161 (Lid): gpiod_set_debounce: missing set() or set_debounce() operations
[ 1.571463] input: gpio-keys as /devices/platform/gpio-keys/input/input2
[ 1.595763] max77686-rtc max77686-rtc: setting system clock to 2015-06-17 12:48:22 UTC (1434545302)
[ 1.624465] TPS65090_RAILSLDO2: disabling
[ 1.626428] TPS65090_RAILSLDO1: disabling
[ 1.629047] TPS65090_RAILSDCDC3: disabling
[ 1.630957] TPS65090_RAILSDCDC2: disabling
[ 1.632809] TPS65090_RAILSDCDC1: disabling
[ 2.232637] EXT4-fs (mmcblk1p5): recovery complete
[ 2.240965] EXT4-fs (mmcblk1p5): mounted filesystem with ordered data mode. Opts: (null)
[ 2.242699] VFS: Mounted root (ext4 filesystem) on device 179:69.
[ 2.253177] devtmpfs: mounted
[ 2.255068] Freeing unused kernel memory: 436K (c0935000 - c09a2000)
[ 5.107336] max77686-rtc max77686-rtc: max77686_rtc_alarm_irq:irq(123)
[ 126.247225] m25p80 spi1.0: from 0x00000000, len 32768
[ 126.247309] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 126.247317] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: not using dma
[ 126.247332] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 126.247338] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: using dma
[ 126.247350] dma-pl330 121b0000.pdma: setting up request on thread 0
[ 126.247354] bc041000: DMAMOV CCR 0x804200
[ 126.247361] bc041006: DMAMOV SAR 0x12d3001c
[ 126.247366] bc04100c: DMAMOV DAR 0x68030000
[ 126.247372] bc041012: DMALP_0 127
[ 126.247377] bc041014: DMALP_1 255
[ 126.247383] bc041016: DMAWFPS 4
[ 126.247388] bc041018: DMALDPS 4
[ 126.247393] bc04101a: DMASTA
[ 126.247398] bc04101b: DMAFLUSHP 4
[ 126.247403] bc04101d: DMALPENDA_1 bjmpto_7
[ 126.247409] bc04101f: DMALPENDA_0 bjmpto_b
[ 126.247414] bc041021: DMASEV 0
[ 126.247419] bc041023: DMAEND
[ 126.247432] spi_master spi1: wait_for_dma: waiting for 160ms transferring 32768bytes@40000000Hz
[ 126.266857] dma-pl330 121b0000.pdma: event signalled on thread id 0
[ 126.266886] spi_master spi1: wait_for_dma: waited 20 ms
[ 126.274513] m25p80 spi1.0: from 0x00000000, len 65536
[ 126.274602] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 126.274610] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: not using dma
[ 126.274625] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 126.274631] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: using dma
[ 126.274643] dma-pl330 121b0000.pdma: setting up request on thread 0
[ 126.274648] bc041000: DMAMOV CCR 0x804200
[ 126.274654] bc041006: DMAMOV SAR 0x12d3001c
[ 126.274660] bc04100c: DMAMOV DAR 0x68030000
[ 126.274665] bc041012: DMALP_0 255
[ 126.274671] bc041014: DMALP_1 255
[ 126.274676] bc041016: DMAWFPS 4
[ 126.274681] bc041018: DMALDPS 4
[ 126.274687] bc04101a: DMASTA
[ 126.274692] bc04101b: DMAFLUSHP 4
[ 126.274697] bc04101d: DMALPENDA_1 bjmpto_7
[ 126.274702] bc04101f: DMALPENDA_0 bjmpto_b
[ 126.274708] bc041021: DMASEV 0
[ 126.274713] bc041023: DMAEND
[ 126.274725] spi_master spi1: wait_for_dma: waiting for 230ms transferring 65536bytes@40000000Hz
[ 126.313573] dma-pl330 121b0000.pdma: event signalled on thread id 0
[ 126.313612] spi_master spi1: wait_for_dma: waited 40 ms
[ 126.324390] m25p80 spi1.0: from 0x00000000, len 131072
[ 126.324476] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 126.324484] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: not using dma
[ 126.324498] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: xfer bpw 8 speed 40000000
[ 126.324504] spi_master spi1: spi1.0 s3c64xx_spi_transfer_one: using dma
[ 126.324516] dma-pl330 121b0000.pdma: setting up request on thread 0
[ 126.324521] bc041000: DMAMOV CCR 0x804200
[ 126.324527] bc041006: DMAMOV SAR 0x12d3001c
[ 126.324533] bc04100c: DMAMOV DAR 0x68040000
[ 126.324539] bc041012: DMALP_0 255
[ 126.324544] bc041014: DMALP_1 255
[ 126.324549] bc041016: DMAWFPS 4
[ 126.324554] bc041018: DMALDPS 4
[ 126.324560] bc04101a: DMASTA
[ 126.324565] bc04101b: DMAFLUSHP 4
[ 126.324570] bc04101d: DMANOP
[ 126.324575] bc04101e: DMANOP
[ 126.324579] bc04101f: DMAWFPS 4
[ 126.324584] bc041021: DMALDPS 4
[ 126.324590] bc041023: DMASTA
[ 126.324594] bc041024: DMAFLUSHP 4
[ 126.324600] bc041026: DMALPENDA_1 bjmpto_10
[ 126.324605] bc041028: DMALPENDA_0 bjmpto_14
[ 126.324610] bc04102a: DMASEV 0
[ 126.324615] bc04102c: DMAEND
[ 126.324628] spi_master spi1: wait_for_dma: waiting for 360ms transferring 131072bytes@40000000Hz
[ 126.730422] spi_master spi1: wait_for_dma: waited 410 ms
[ 126.730433] m25p80 spi1.0: I/O Error: rx-1 tx-0 res:rx-f tx-p len-131072
[ 126.730445] m25p80 spi1.0: SPI transfer failed: -5
[ 126.730503] spi_master spi1: failed to transfer one message from queue
