Thanks for Leo, I find this new patch https://github.com/openwrt/openwrt/pull/1954.
This patch increases a lot of SPI speed. I have a quick check, looks like it speeds up because of morebuf mode.

...

	/*
	 * Select SPI device 7, enable "more buffer mode" and disable
	 * full-duplex (only half-duplex really works on this chip
	 * reliably)
	 */
	master = mt7621_spi_read(rs, MT7621_SPI_MASTER);
	master |= MASTER_RS_SLAVE_SEL | MASTER_MORE_BUFMODE;
	master &= ~MASTER_FULL_DUPLEX;
	mt7621_spi_write(rs, MT7621_SPI_MASTER, master);

...

static void mt7621_spi_read_half_duplex(struct mt7621_spi *rs,
					int rx_len, u8 *buf)
...
		mt7621_spi_write(rs, MT7621_SPI_MOREBUF, val);

That is nice. A good example about morebuf mode, this should be an important mode for dma. This code saves me a lot time, now I can directly try interrupt and dma.

Currently DMA source address can be fixed and max burst size is 16DWs, in morebuf + half duplex mode we use 8DWs. So DMA should work no problem. We will see later 🙂

30 seconds to start wifi, it is a long time for some situation.
Why does it take so long time to boost. Let’s check!

Now, prepare a firmware, better compile from source code, so we can easily cut off kernel of Linux.

I am using 20190914.bin firmware.

First try, remove all boot up module from system.

1. mv /etc/init.d /etc/init.d.bak
2. mv /etc/modules.d /etc/modules.d.bak
3. mkdir /etc/init.d
4. mkdir /etc/modules.d

Now reboot, you will get this log, looks like it is able to startup around 9 seconds.


Starting kernel ...

[    0.000000] Linux version 4.14.131 (vonger@Vongers-MacBook-Pro-2.local) (gcc version 7.3.0 (OpenWrt GCC 7.3.0 r7808-ef686b7292)) #0 Thu Jun 27 12:18:52 2019
[    0.000000] Board has DDR2
[    0.000000] Analog PMU set to hw control
[    0.000000] Digital PMU set to hw control
[    0.000000] SoC Type: MediaTek MT7628AN ver:1 eco:2
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019655 (MIPS 24KEc)
[    0.000000] MIPS: machine is VoCore2
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 08000000 @ 00000000 (usable)
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] random: get_random_bytes called from start_kernel+0x90/0x478 with crng_init=0
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line: console=ttyS2,115200 console=tty0 fbcon=rotate:3 rootfstype=squashfs,jffs2
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Writing ErrCtl register=00016cbe
[    0.000000] Readback ErrCtl register=00016cbe
[    0.000000] Memory: 125136K/131072K available (3295K kernel code, 176K rwdata, 816K rodata, 184K init, 210K bss, 5936K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS: 256
[    0.000000] intc: using register map from devicetree
[    0.000000] CPU Clock: 580MHz
[    0.000000] timer_probe: no matching timers found
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6590553264 ns
[    0.000011] sched_clock: 32 bits at 290MHz, resolution 3ns, wraps every 7405115902ns
[    0.008031] Console: colour dummy device 80x25
[    0.012460] console [tty0] enabled
[    0.015887] bootconsole [early0] disabled
[    0.000000] Linux version 4.14.131 (vonger@Vongers-MacBook-Pro-2.local) (gcc version 7.3.0 (OpenWrt GCC 7.3.0 r7808-ef686b7292)) #0 Thu Jun 27 12:18:52 2019
[    0.000000] Board has DDR2
[    0.000000] Analog PMU set to hw control
[    0.000000] Digital PMU set to hw control
[    0.000000] SoC Type: MediaTek MT7628AN ver:1 eco:2
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019655 (MIPS 24KEc)
[    0.000000] MIPS: machine is VoCore2
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 08000000 @ 00000000 (usable)
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] random: get_random_bytes called from start_kernel+0x90/0x478 with crng_init=0
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line: console=ttyS2,115200 console=tty0 fbcon=rotate:3 rootfstype=squashfs,jffs2
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Writing ErrCtl register=00016cbe
[    0.000000] Readback ErrCtl register=00016cbe
[    0.000000] Memory: 125136K/131072K available (3295K kernel code, 176K rwdata, 816K rodata, 184K init, 210K bss, 5936K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS: 256
[    0.000000] intc: using register map from devicetree
[    0.000000] CPU Clock: 580MHz
[    0.000000] timer_probe: no matching timers found
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6590553264 ns
[    0.000011] sched_clock: 32 bits at 290MHz, resolution 3ns, wraps every 7405115902ns
[    0.008031] Console: colour dummy device 80x25
[    0.012460] console [tty0] enabled
[    0.015887] bootconsole [early0] disabled
[    0.019985] Calibrating delay loop... 385.84 BogoMIPS (lpj=1929216)
[    0.079986] pid_max: default: 32768 minimum: 301
[    0.080256] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.080289] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.086071] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.086134] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.086275] pinctrl core: initialized pinctrl subsystem
[    0.086858] NET: Registered protocol family 16
[    0.117626] mt7621_gpio 10000600.gpio: registering 32 gpios
[    0.117933] mt7621_gpio 10000600.gpio: registering 32 gpios
[    0.118181] mt7621_gpio 10000600.gpio: registering 32 gpios
[    0.122205] clocksource: Switched to clocksource MIPS
[    0.129577] NET: Registered protocol family 2
[    0.130562] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.130628] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.130676] TCP: Hash tables configured (established 1024 bind 1024)
[    0.130874] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.130931] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.131236] NET: Registered protocol family 1
[    0.147182] Crashlog allocated RAM at address 0x3f00000
[    0.148548] workingset: timestamp_bits=30 max_order=15 bucket_order=0
[    0.154546] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.154646] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.165214] io scheduler noop registered
[    0.165319] io scheduler deadline registered (default)
[    0.166334] Serial: 8250/16550 driver, 3 ports, IRQ sharing disabled
[    0.167733] 10000c00.uartlite: ttyS0 at MMIO 0x10000c00 (irq = 28, base_baud = 2500000) is a 16550A
[    0.168556] 10000d00.uart1: ttyS1 at MMIO 0x10000d00 (irq = 29, base_baud = 2500000) is a 16550A
[    0.169347] 10000e00.uart2: ttyS2 at MMIO 0x10000e00 (irq = 30, base_baud = 2500000) is a 16550A
[    0.575929] console [ttyS2] enabled
[    0.580140] cacheinfo: Failed to find cpu0 device node
[    0.585466] cacheinfo: Unable to detect cache hierarchy for CPU 0
[    0.592524] spi-mt7621 10000b00.spi: sys_freq: 193333333
[    0.602293] m25p80 spi0.0: gd25q128 (16384 Kbytes)
[    0.607306] 4 fixed-partitions partitions found on MTD device spi0.0
[    0.613836] Creating 4 MTD partitions on "spi0.0":
[    0.618760] 0x000000000000-0x000000030000 : "u-boot"
[    0.624825] 0x000000030000-0x000000040000 : "u-boot-env"
[    0.631139] 0x000000040000-0x000000050000 : "factory"
[    0.637312] 0x000000050000-0x000001000000 : "firmware"
[    0.714902] 2 uimage-fw partitions found on MTD device firmware
[    0.721015] 0x000000050000-0x0000001b241c : "kernel"
[    0.727045] 0x0000001b241c-0x000001000000 : "rootfs"
[    0.733053] mtd: device 5 (rootfs) set to be root filesystem
[    0.740445] 1 squashfs-split partitions found on MTD device rootfs
[    0.746881] 0x000000380000-0x000001000000 : "rootfs_data"
[    0.754141] libphy: Fixed MDIO Bus: probed
[    0.768547] rt3050-esw 10110000.esw: link changed 0x00
[    0.777025] mtk_soc_eth 10100000.ethernet eth0: mediatek frame engine at 0xb0100000, irq 5
[    0.786704] NET: Registered protocol family 17
[    0.791363] 8021q: 802.1Q VLAN Support v1.8
[    0.807897] VFS: Mounted root (squashfs filesystem) readonly on device 31:5.
[    0.816223] Freeing unused kernel memory: 184K
[    0.820806] This architecture does not have kernel memory protection.
[    2.100970] init: Console is alive
[    2.104845] init: - watchdog -
[    2.362212] random: fast init done
[    2.883744] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    2.965047] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    2.974500] init: - preinit -
[    4.114342] rt3050-esw 10110000.esw: link changed 0x00
[    7.649323] jffs2: notice: (412) jffs2_build_xattr_subsystem: complete building xattr subsystem, 10 of xdatum (2 unchecked, 7 orphan) and 78 of xref (4 dead, 43 orphan) found.
[    7.667350] mount_root: switching to jffs2 overlay
[    7.692257] overlayfs: upper fs does not support tmpfile.
[    7.705332] urandom-seed: Seed file not found (/etc/urandom.seed)
[    7.909840] procd: - early -
[    7.913758] procd: - watchdog -
[    8.630091] procd: - watchdog -
[    8.633709] procd: - ubus -
[    8.867640] random: ubusd: uninitialized urandom read (4 bytes read)
[    9.024867] random: ubusd: uninitialized urandom read (4 bytes read)
[    9.031955] random: ubusd: uninitialized urandom read (4 bytes read)
[    9.039617] procd: - init -
Please press Enter to activate this console.

9s is still too long, because we did not load wifi driver yet, wifi driver is pretty big and slow…

From begin to 0.82s, everything seems fast and pretty, but after that, at 2.1s, init runs, suddenly, it becomes very slow, we can find an obviously time span at 2.1s, 4.1s and 7.6s.

Emm, why?

I have some guesses:

1. it is because SPI load something from flash and SPI is slow(busy wait, no dma, check my blog about SPI). Once the file system like jffs2 is doing some dirty job, it will slow down the boot.
2. some unknown drivers load by init takes too much time, slow down the boot speed.

As I know, even the driver as big as mt7628.ko(wifi driver), won’t take more than two seconds to load, so it must be something nasty at its boot time.

OpenWrt drivers mostly are port from ralink SDK, they just work but not optimize to the best(maybe ralink is too poor to hire engineer work on this…), so I should have some space to optimize the code. 🙂

My target is to make it boot into 5s, with wifi into 10s.
To be continue…

Now in the deep zone.

From /proc/interrupts, I know esw, gdma, sdhci etc have interrupts.

Check gdma source code, we can add similar irq code to spi.

static irqreturn_t mt7621_spi_irq(int irq, void *devid)
{
	struct mt7621_spi *rs = (struct mt7621_spi *)devid;
	printk(KERN_INFO "mt7621_spi_irq %d trigger\n", irq);
	return IRQ_HANDLED;
}

...

	irq = platform_get_irq(pdev, 0);
	if (irq < 0) { dev_err(&pdev->dev, "failed to get irq\n");
		return -EINVAL;
	}
	ret = devm_request_irq(&pdev->dev, irq, mt7621_spi_irq,
			0, dev_name(&pdev->dev), rs);
	if (ret) {
		dev_err(&pdev->dev, "failed to request irq\n");
		return ret;
	}

and in vocore2 dts(device tree, mt7628an.dtsi), we also need to add spi interrupt.

                spi0: spi@b00 {
                        compatible = "ralink,mt7621-spi";
                        reg = <0xb00 0x100>;

                        resets = <&rstctrl 18>;
                        reset-names = "spi";

                        #address-cells = <1>;
                        #size-cells = <0>;

                        pinctrl-names = "default";
                        pinctrl-0 = <&spi_pins>;

                        interrupt-parent = <&intc>;
                        interrupts = <11>;

                        status = "disabled";
                };

OK, that all, we can compile and check if this works.

After VoCore2 upgrade ready and flash init ready, we can call mem command(I write this command for easy debug, source code can be downloaded at vocore.io/v2.html) to enable spi interrupt.

mem 0x10000b28 0xe0128a84 

Then, write something through spi, like ‘touch /root/x’, this will create a new file under /root/, so OS will try to use spi write to the flash.

Ouch… I just get endless messages “mt7621_spi_irq 19 trigger” from console, after a while, the system dead.

I guess there must be something wrong in the interrupt code. As I remember, once interrupt is triggered, we must write to some register to clean the interrupt, or it will keep in trigger status, that will cause a deadloop, system will hang up too.

Checking esw(ethernet switch) source code, I find esw 0x00 register is Interrupt Status Register, once you write same thing into the register, it will clean up the interrupt.

So SPI must has something similar.

Finally I find it is 0x10000b34 register, its name is SPI Status. The final bit of it:

Once the register is read by system, the interrupt will be clear, easy 😉

Update IRQ code to the following code

static irqreturn_t mt7621_spi_irq(int irq, void *devid)
{
	struct mt7621_spi *rs = (struct mt7621_spi *)devid;
	u32 reg;

	reg = mt7621_spi_read(rs, MT7621_SPI_STATUS);
	printk(KERN_INFO "mt7621_spi_irq %d trigger, status 0x%08x\n", irq, reg);
	return IRQ_HANDLED;
}

Now once we touch new file into flash, we just get around ten lines of the kernel interrupt log, that means, it works! Check system, spi interrupt is not zero anymore.

root@OpenWrt:~# cat /proc/interrupts 
           CPU0       
  5:        895      MIPS   5  10100000.ethernet
  6:      50378      MIPS   6  ra0
  7:     266055      MIPS   7  timer
 15:          0      INTC   7  10002800.gdma
 19:        138      INTC  11  10000b00.spi
 22:      79014      INTC  14  10130000.sdhci
 25:          2      INTC  17  esw
 26:          1      INTC  18  ehci_hcd:usb1, ohci_hcd:usb2
 30:        440      INTC  22  ttyS2
ERR:          0

Next I will try to combine the interrupt into the source code, this is pretty risk, because once Linux boot up, it is using this driver read from flash.
Next next, if I have any luck go that far, maybe try GDMA with SPI, then we have some fast speed spi devices.

Continue with last blog…

PS: because I am a totally noob of kernel develop, the process is pretty slow 🙂

I only have a little experience on DMA, I2S and sound codec…for SPI part, still a blank paper. This blog must be hard to understand and very few people will read, but the process is pretty fun for me.

For a common vocore2, once it boot up, the SPI control register 0x10000b28 is like this:

root@OpenWrt:/# mem 0x10000b28 bit
31:1 30:1 29:1 28:0 27:0 26:0 25:0 24:0 23:0 22:0 21:0 20:1 19:0 18:0 17:1 16:0 
15:1 14:0 13:0 12:0 11:1 10:0 09:0 08:0 07:1 06:0 05:0 04:0 03:0 02:1 01:0 00:0

Its ninth bit is int_en, I guess that should be enabled.

Then read datasheet(pretty painful for me) page 11/347, we can find:

So SPI interrupt is 11(0x0b)

Let’s check interrupt register, 0x10000270.
For my VoCore2, the result like this:

root@OpenWrt:~# mem 0x10000270 bit
31:1 30:0 29:0 28:0 27:0 26:0 25:0 24:0 23:0 22:1 21:0 20:0 19:0 18:1 17:1 16:0 
15:0 14:1 13:0 12:0 11:0 10:0 09:0 08:0 07:1 06:1 05:0 04:0 03:0 02:0 01:0 00:0 

22 is UART-Lite2, which we used it for debug console.
18 is USB20, so from its name it should be USB2.0.
17 is ESW, from its name it should be ethernet switcher.
14 is SDXC, absolutely for SD card.
07 is GDMA, general DMA, for sound and i2s we use it to boost up speed.
06 is GPIO, so for fast GPIO it should be useful, like trigger button by low to high voltage edge.
11 is SPI, currently the driver is not used, that is what I will going to do.
31 is not there…as I know it is for soft interrupt, once I read code about it, but can not remember where it is.

I have no idea where to start.
Let’s check GDMA driver first, in dts/MT7628AN.dtsi(openwrt source code)

                gdma: gdma@2800 {
                        compatible = "ralink,rt3883-gdma";
                        reg = <0x2800 0x800>;

                        resets = <&rstctrl 14>;
                        reset-names = "dma";

                        interrupt-parent = <&intc>;
                        interrupts = <7>;

                        #dma-cells = <1>;
                        #dma-channels = <16>;
                        #dma-requests = <16>;

                        status = "disabled";
                };

We can find it has intc at <7>, and in its source code, it connects interrupt with this source code. driver/dma/ralink-gdma.c (linux source code)

	res = platform_get_resource(pdev, IORESOURCE_MEM, 0);
	base = devm_ioremap_resource(&pdev->dev, res);
	if (IS_ERR(base))
		return PTR_ERR(base);
	dma_dev->base = base;
	tasklet_init(&dma_dev->task, gdma_dma_tasklet, (unsigned long)dma_dev);

so once the interrupt is triggered, the kernel should call gdma_dma_tasklet.

Next blog I will update the spi driver source code in linux to check if this interrupt works 😉