Custom Linux is 1000x slower

bmorcos · February 1, 2017, 9:37pm

I am using an Altera Cyclone V SoC dev board.

I built a custom Linux platform using Yocto and I finally got everything working and in a state in which I could run my AOCL program… However my FPGA program now runs about 1000x slower than when I use a prebuilt image. I am getting the following error on boot and I am guessing that it is related to the poor performance:

INIT: Entering runlevel: 5misc/rtc': No such file or directory```

There are no rtc files on the board as far as I can tell (`find / -name "*rtc*"` returns nothing).

Two questions then:

1. Any ideas why I am taking a 1000x performance hit using my custom Linux build?
2. If my assumptions are correct in that the hwclock/rtc is the culprit, any ideas on how to rectify this? or add something to my Yocto build or device tree or something?

bmorcos · February 3, 2017, 6:55pm

UPDATE:
I’ve modified my my Linux image and fixed the issue with the rtc, however this did not help the performance!

Some interesting behaviour though, I launch my AOCL kernel multiple times, the first launch has execution times that appear to be in the ideal range of 0 < t < 1000ms, and all subsequent launches report times of almost exactly t=1000ms. This leads me to believe that there is a 1s clock somewhere that is responsible for the performance hit. My thinking is the first kernel launch could fall anywhere in the clock cycle, and returns on the next edge, hence 0 < t < 1000, whereas subsequent launches will occur on the clock edge, hence t=1000ms.

I also tested the vector_add example on my custom image and the prebuilt image (16.1); with my custom image it reports variable kernel time on the order of 0 < t < 1000ms like I was seeing with my kernel. Using the prebuilt image I get consistent performance around t=8.5ms.

I would love to hear your thoughts and suggestions!

bmorcos · February 8, 2017, 5:25pm

Here is the boot dump from my current build… maybe something will jump out to somebody with more experience!

U-Boot SPL 2013.01.01 (Dec 04 2014 - 08:59:41)
BOARD : Altera SOCFPGA Cyclone V Board
CLOCK: EOSC1 clock 25000 KHz
CLOCK: EOSC2 clock 25000 KHz
CLOCK: F2S_SDR_REF clock 0 KHz
CLOCK: F2S_PER_REF clock 0 KHz
CLOCK: MPU clock 925 MHz
CLOCK: DDR clock 400 MHz
CLOCK: UART clock 100000 KHz
CLOCK: MMC clock 50000 KHz
CLOCK: QSPI clock 370000 KHz
RESET: COLD
SDRAM: Initializing MMR registers
SDRAM: Calibrating PHY
SEQ.C: Preparing to start memory calibration
SEQ.C: CALIBRATION PASSED
SDRAM: 1024 MiB
SDRAM: ECC Enabled
ALTERA DWMMC: 0


U-Boot 2013.01.01-00132-gd141e21 (Feb 07 2017 - 16:00:35)

CPU   : Altera SOCFPGA Platform
BOARD : Altera SOCFPGA Cyclone V Board
I2C:   ready
DRAM:  1 GiB
MMC:   ALTERA DWMMC: 0
*** Warning - bad CRC, using default environment

In:    serial
Out:   serial
Err:   serial
Net:   mii0
Hit any key to stop autoboot:  0
reading u-boot.scr
200 bytes read in 3 ms (64.5 KiB/s)
## Executing script at 02000000
reading soc_system.rbf
3655972 bytes read in 179 ms (19.5 MiB/s)
## Starting application at 0x3FF7A504 ...
## Application terminated, rc = 0x0
reading zImage
3893224 bytes read in 187 ms (19.9 MiB/s)
reading socfpga.dtb
20378 bytes read in 5 ms (3.9 MiB/s)
## Flattened Device Tree blob at 00000100
   Booting using the fdt blob at 0x00000100
   reserving fdt memory region: addr=0 size=1000
   Loading Device Tree to 03ff8000, end 03ffff99 ... OK

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Linux version 4.3.0-altera (ben@localhost.localdomain) (gcc version 5.2.1 20151005 (Linaro GCC 5.2-2015.11-2) ) #1 SMP Tue Feb 7 16:04:21 EST 2017
[    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: Altera SOCFPGA Cyclone V SoC Development Kit
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] PERCPU: Embedded 13 pages/cpu @eefc9000 s21760 r8192 d23296 u53248
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 260624
[    0.000000] Kernel command line: console=ttyS0,115200 root=/dev/mmcblk0p2 rw rootwait
[    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: 1030856K/1048576K available (5957K kernel code, 399K rwdata, 1536K rodata, 424K init, 155K bss, 17720K reserved, 0K cma-reserved, 270336K highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 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 - 0xc075985c   (7495 kB)
[    0.000000]       .init : 0xc075a000 - 0xc07c4000   ( 424 kB)
[    0.000000]       .data : 0xc07c4000 - 0xc0827d70   ( 400 kB)
[    0.000000]        .bss : 0xc0827d70 - 0xc084ea9c   ( 156 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  Build-time adjustment of leaf fanout to 32.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] L2C: platform modifies aux control register: 0x02060000 -> 0x32460000
[    0.000000] L2C: platform provided aux values permit register corruption.
[    0.000000] L2C: DT/platform modifies aux control register: 0x02060000 -> 0x32460000
[    0.000000] L2C-310 erratum 769419 enabled
[    0.000000] L2C-310 enabling early BRESP for Cortex-A9
[    0.000000] L2C-310 full line of zeros enabled for Cortex-A9
[    0.000000] L2C-310 ID prefetch enabled, offset 1 lines
[    0.000000] L2C-310 dynamic clock gating enabled, standby mode enabled
[    0.000000] L2C-310 cache controller enabled, 8 ways, 512 kB
[    0.000000] L2C-310: CACHE_ID 0x410030c9, AUX_CTRL 0x76460001
[    0.000000] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.000005] sched_clock: 32 bits at 100MHz, resolution 10ns, wraps every 21474836475ns
[    0.000160] Console: colour dummy device 80x30
[    0.000182] Calibrating delay loop... 1836.64 BogoMIPS (lpj=9183232)
[    0.059821] pid_max: default: 32768 minimum: 301
[    0.059911] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.059922] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.060492] CPU: Testing write buffer coherency: ok
[    0.060520] ftrace: allocating 19839 entries in 59 pages
[    0.090921] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.091147] Setting up static identity map for 0x8280 - 0x82d8
[    0.149843] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.149909] Brought up 2 CPUs
[    0.149923] SMP: Total of 2 processors activated (3679.84 BogoMIPS).
[    0.149929] CPU: All CPU(s) started in SVC mode.
[    0.150668] devtmpfs: initialized
[    0.155515] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[    0.155769] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.156970] NET: Registered protocol family 16
[    0.157046] fpga bridge driver
[    0.158077] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.164726] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
[    0.164739] hw-breakpoint: maximum watchpoint size is 4 bytes.
[    0.165330] altera_hps2fpga_bridge soc:fpgabridge@0: fpga bridge [hps2fpga] registered as device hps2fpga
[    0.165345] altera_hps2fpga_bridge soc:fpgabridge@0: init-val not specified
[    0.165559] altera_hps2fpga_bridge soc:fpgabridge@1: fpga bridge [lwhps2fpga] registered as device lwhps2fpga
[    0.165572] altera_hps2fpga_bridge soc:fpgabridge@1: init-val not specified
[    0.165790] altera_hps2fpga_bridge soc:fpgabridge@2: fpga bridge [fpga2hps] registered as device fpga2hps
[    0.165803] altera_hps2fpga_bridge soc:fpgabridge@2: init-val not specified
[    0.183906] FPGA Mangager framework driver
[    0.184202] SCSI subsystem initialized
[    0.184460] usbcore: registered new interface driver usbfs
[    0.184521] usbcore: registered new interface driver hub
[    0.184577] usbcore: registered new device driver usb
[    0.184728] soc:usbphy@0 supply vcc not found, using dummy regulator
[    0.185828] lcd_load_custom_fonts: i2c_master_send returns -121
[    0.192875] lcd_cmd_no_params: i2c_master_send returns -121
[    0.202522] lcd_cmd_one_param: i2c_master_send returns -121
[    0.212516] lcd_cmd_no_params: i2c_master_send returns -121
[    0.212542] lcd-comm 0-0028: LCD driver initialized
[    0.212917] pps_core: LinuxPPS API ver. 1 registered
[    0.212926] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.212958] PTP clock support registered
[    0.213847] clocksource: Switched to clocksource timer1
[    0.244136] NET: Registered protocol family 2
[    0.244660] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.244729] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.244835] TCP: Hash tables configured (established 8192 bind 8192)
[    0.244912] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.244991] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.245194] NET: Registered protocol family 1
[    0.245451] RPC: Registered named UNIX socket transport module.
[    0.245461] RPC: Registered udp transport module.
[    0.245467] RPC: Registered tcp transport module.
[    0.245472] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.245803] hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available
[    0.245876] armv7-pmu arm-pmu: PMU:CTI successfully enabled for 2 cores
[    0.246821] futex hash table entries: 512 (order: 3, 32768 bytes)
[    0.256039] NFS: Registering the id_resolver key type
[    0.256078] Key type id_resolver registered
[    0.256085] Key type id_legacy registered
[    0.256140] ntfs: driver 2.1.32 [Flags: R/W].
[    0.256463] jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
[    0.257686] bounce: pool size: 64 pages
[    0.257704] io scheduler noop registered (default)
[    0.263424] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
[    0.264589] console [ttyS0] disabled
[    0.264628] ffc02000.serial0: ttyS0 at MMIO 0xffc02000 (irq = 47, base_baud = 6250000) is a 16550A
[    0.911521] console [ttyS0] enabled
[    0.915560] ffc03000.serial1: ttyS1 at MMIO 0xffc03000 (irq = 48, base_baud = 6250000) is a 16550A
[    0.925319] altera_fpga_manager ff706000.fpgamgr: fpga manager [Altera FPGA Manager] registered as minor 0
[    0.936572] brd: module loaded
[    0.939687] at24 0-0051: 4096 byte 24c32 EEPROM, writable, 32 bytes/write
[    0.947192] cadence-qspi ff705000.spi: Read data capture delay for 100000000 baud calibrated to 4 (2 - 5)
[    0.956794] cadence-qspi ff705000.spi: n25q512ax3 (65536 Kbytes)
[    0.962911] 2 ofpart partitions found on MTD device ff705000.spi
[    0.968925] Creating 2 MTD partitions on "ff705000.spi":
[    0.974242] 0x000000000000-0x000000800000 : "Flash 0 Raw Data"
[    0.980924] 0x000000800000-0x000008000000 : "Flash 0 jffs2 Filesystem"
[    0.987445] mtd: partition "Flash 0 jffs2 Filesystem" extends beyond the end of device "ff705000.spi" -- size truncated to 0x3800000
[    1.000077] cadence-qspi ff705000.spi: Cadence QSPI NOR flash driver
[    1.007260] spidev spi32766.0: buggy DT: spidev listed directly in DT
[    1.013678] ------------[ cut here ]------------
[    1.018302] WARNING: CPU: 1 PID: 1 at /home/ben/git/build/tmp/work-shared/cyclone5/kernel-source/drivers/spi/spidev.c:719 spidev_probe+0x1b8/0x1d4()
[    1.031559] Modules linked in:
[    1.034628] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.3.0-altera #1
[    1.041039] Hardware name: Altera SOCFPGA
[    1.045068] [<c001891c>] (unwind_backtrace) from [<c0014430>] (show_stack+0x20/0x24)
[    1.052790] [<c0014430>] (show_stack) from [<c02c4274>] (dump_stack+0x80/0x90)
[    1.059999] [<c02c4274>] (dump_stack) from [<c0026f94>] (warn_slowpath_common+0x94/0xc4)
[    1.068070] [<c0026f94>] (warn_slowpath_common) from [<c0027080>] (warn_slowpath_null+0x2c/0x34)
[    1.076827] [<c0027080>] (warn_slowpath_null) from [<c0380838>] (spidev_probe+0x1b8/0x1d4)
[    1.085073] [<c0380838>] (spidev_probe) from [<c037dd78>] (spi_drv_probe+0x60/0x84)
[    1.092711] [<c037dd78>] (spi_drv_probe) from [<c03306ec>] (driver_probe_device+0x254/0x2f8)
[    1.101127] [<c03306ec>] (driver_probe_device) from [<c03308c4>] (__device_attach_driver+0x94/0xbc)
[    1.110152] [<c03308c4>] (__device_attach_driver) from [<c032e848>] (bus_for_each_drv+0x70/0xa4)
[    1.118913] [<c032e848>] (bus_for_each_drv) from [<c03303e4>] (__device_attach+0xc0/0x124)
[    1.127155] [<c03303e4>] (__device_attach) from [<c0330948>] (device_initial_probe+0x1c/0x20)
[    1.135656] [<c0330948>] (device_initial_probe) from [<c032f86c>] (bus_probe_device+0x94/0x9c)
[    1.144243] [<c032f86c>] (bus_probe_device) from [<c032d790>] (device_add+0x380/0x57c)
[    1.152131] [<c032d790>] (device_add) from [<c037e7ac>] (spi_add_device+0xa8/0x140)
[    1.159768] [<c037e7ac>] (spi_add_device) from [<c03800f8>] (spi_register_master+0x4dc/0x748)
[    1.168269] [<c03800f8>] (spi_register_master) from [<c03803a4>] (devm_spi_register_master+0x40/0x78)
[    1.177461] [<c03803a4>] (devm_spi_register_master) from [<c03820a4>] (dw_spi_add_host+0x164/0x240)
[    1.186478] [<c03820a4>] (dw_spi_add_host) from [<c0382580>] (dw_spi_mmio_probe+0x1f4/0x24c)
[    1.194892] [<c0382580>] (dw_spi_mmio_probe) from [<c0332468>] (platform_drv_probe+0x54/0xbc)
[    1.203384] [<c0332468>] (platform_drv_probe) from [<c03306ec>] (driver_probe_device+0x254/0x2f8)
[    1.212230] [<c03306ec>] (driver_probe_device) from [<c033082c>] (__driver_attach+0x9c/0xa0)
[    1.220647] [<c033082c>] (__driver_attach) from [<c032e778>] (bus_for_each_dev+0x78/0xac)
[    1.228802] [<c032e778>] (bus_for_each_dev) from [<c032ff34>] (driver_attach+0x2c/0x30)
[    1.236789] [<c032ff34>] (driver_attach) from [<c032fb38>] (bus_add_driver+0x1b0/0x228)
[    1.244772] [<c032fb38>] (bus_add_driver) from [<c03311c4>] (driver_register+0x88/0x108)
[    1.252831] [<c03311c4>] (driver_register) from [<c0332394>] (__platform_driver_register+0x64/0x6c)
[    1.261850] [<c0332394>] (__platform_driver_register) from [<c0783824>] (dw_spi_mmio_driver_init+0x1c/0x20)
[    1.271561] [<c0783824>] (dw_spi_mmio_driver_init) from [<c0009800>] (do_one_initcall+0x9c/0x1e4)
[    1.280413] [<c0009800>] (do_one_initcall) from [<c075aed0>] (kernel_init_freeable+0x1e8/0x280)
[    1.289090] [<c075aed0>] (kernel_init_freeable) from [<c055e6e8>] (kernel_init+0x1c/0xf8)
[    1.297247] [<c055e6e8>] (kernel_init) from [<c000fcf8>] (ret_from_fork+0x14/0x3c)
[    1.304803] ---[ end trace 44735858e6084ea3 ]---
[    1.310478] CAN device driver interface
[    1.315004] c_can_platform ffc00000.can: c_can_platform device registered (regs=f00fc000, irq=26)
[    1.324297] stmmac - user ID: 0x10, Synopsys ID: 0x37
[    1.329328]  Ring mode enabled
[    1.332367]  DMA HW capability register supported
[    1.336891]  Enhanced/Alternate descriptors
[    1.341237]  Enabled extended descriptors
[    1.345236]  RX Checksum Offload Engine supported (type 2)
[    1.350694]  TX Checksum insertion supported
[    1.354949]  Enable RX Mitigation via HW Watchdog Timer
[    1.366100] libphy: stmmac: probed
[    1.369495] eth0: PHY ID 00221611 at 4 IRQ POLL (stmmac-0:04) active
[    1.673869] ffb40000.usb supply vusb_d not found, using dummy regulator
[    1.680500] ffb40000.usb supply vusb_a not found, using dummy regulator
[    1.723851] dwc2 ffb40000.usb: EPs: 16, dedicated fifos, 8064 entries in SPRAM
[    2.283939] dwc2 ffb40000.usb: DWC OTG Controller
[    2.288647] dwc2 ffb40000.usb: new USB bus registered, assigned bus number 1
[    2.295702] dwc2 ffb40000.usb: irq 49, io mem 0x00000000
[    2.301140] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    2.307914] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.315115] usb usb1: Product: DWC OTG Controller
[    2.319799] usb usb1: Manufacturer: Linux 4.3.0-altera dwc2_hsotg
[    2.325874] usb usb1: SerialNumber: ffb40000.usb
[    2.330969] hub 1-0:1.0: USB hub found
[    2.334750] hub 1-0:1.0: 1 port detected
[    2.339278] usbcore: registered new interface driver usb-storage
[    2.345642] mousedev: PS/2 mouse device common for all mice
[    2.353555] rtc-ds1307 0-0068: SET TIME!
[    2.360090] rtc-ds1307 0-0068: read error -121
[    2.364709] rtc-ds1307 0-0068: rtc core: registered ds1339 as rtc0
[    2.370906] i2c /dev entries driver
[    2.375205] Synopsys Designware Multimedia Card Interface Driver
[    2.381463] dw_mmc ff704000.dwmmc0: IDMAC supports 32-bit address mode.
[    2.388102] dw_mmc ff704000.dwmmc0: Using internal DMA controller.
[    2.394273] dw_mmc ff704000.dwmmc0: Version ID is 240a
[    2.399427] dw_mmc ff704000.dwmmc0: DW MMC controller at irq 35,32 bit host data width,1024 deep fifo
[    2.408754] dw_mmc ff704000.dwmmc0: Got CD GPIO
[    2.443873] dw_mmc ff704000.dwmmc0: 1 slots initialized
[    2.449744] ledtrig-cpu: registered to indicate activity on CPUs
[    2.455943] usbcore: registered new interface driver usbhid
[    2.461491] usbhid: USB HID core driver
[    2.465522] oprofile: using arm/armv7-ca9
[    2.470456] NET: Registered protocol family 10
[    2.475605] sit: IPv6 over IPv4 tunneling driver
[    2.480810] NET: Registered protocol family 17
[    2.483298] mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 50000000Hz, actual 50000000HZ div = 0)
[    2.483356] mmc0: new high speed SDHC card at address 0003
[    2.483871] mmcblk0: mmc0:0003 SD4GB 3.67 GiB
[    2.484744]  mmcblk0: p1 p2 p3
[    2.507931] NET: Registered protocol family 15
[    2.512361] can: controller area network core (rev 20120528 abi 9)
[    2.518586] NET: Registered protocol family 29
[    2.523028] can: raw protocol (rev 20120528)
[    2.527300] can: broadcast manager protocol (rev 20120528 t)
[    2.532943] can: netlink gateway (rev 20130117) max_hops=1
[    2.538626] 8021q: 802.1Q VLAN Support v1.8
[    2.542842] Key type dns_resolver registered
[    2.547188] ThumbEE CPU extension supported.
[    2.551454] Registering SWP/SWPB emulation handler
[    2.559323] ttyS0 - failed to request DMA
[    2.567578] VFS: Mounted root (ext2 filesystem) on device 179:2.
[    2.574519] devtmpfs: mounted
[    2.577793] Freeing unused kernel memory: 424K (c075a000 - c07c4000)
INIT: version 2.88 booting
Starting udev
[    2.914177] udevd[661]: starting version 182
[    3.285507] random: dd urandom read with 35 bits of entropy available
Populating dev cache
Tue Feb  7 21:06:39 UTC 2017
INIT: Entering runlevel: 5
Configuring network interfaces... udhcpc (v1.23.2) started
Sending discover...
Sending discover...
[    8.014421] socfpga-dwmac ff702000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Sending discover...
Sending select for 10.162.177.237...
Lease of 10.162.177.237 obtained, lease time 86400
/etc/udhcpc.d/50default: Adding DNS 10.162.177.1
done.
Starting OpenBSD Secure Shell server: sshd
  generating ssh RSA key...
  generating ssh ECDSA key...
  generating ssh DSA key...
  generating ssh ED25519 key...
done.
Starting syslogd/klogd: done

lionel · February 8, 2017, 5:34pm

When you say that your FPGA program is 1000x slower, do you mean a software program running on Linux or the speed of a design synthesized on the FPGA?

Have you tried comparing the kernel boot messages between the working prebuilt image and your custom kernel?

In particular this line could be of interest:

Comparing the output of cat /proc/cpuinfo could also shed some light on what’s going on. That’s assuming that the problem in on the CPU side, if it’s on the FPGA it probably won’t help at all.

bmorcos · February 8, 2017, 6:28pm

Thanks for the reply!

The reported FPGA kernel time is what is slower, and it appears as though the software side is running at a normal speed. /proc/cpuinfo is the same for my custom build and the prebuilt, as well as the line you quoted which is identical in the prebuilt boot dump. I have been comparing to a prebuilt boot dump and managed to rectify a few odd messages (prior to what I posted above) but none of them seemed to fix the slowness.

Here is the prebuilt for reference (image shipped with Intel/Altera OpenCL SDK 16.1)

U-Boot SPL 2013.01.01 (Apr 25 2014 - 04:59:26)
BOARD : Altera SOCFPGA Cyclone V Board
CLOCK: EOSC1 clock 25000 KHz
CLOCK: EOSC2 clock 25000 KHz
CLOCK: F2S_SDR_REF clock 0 KHz
CLOCK: F2S_PER_REF clock 0 KHz
CLOCK: MPU clock 925 MHz
CLOCK: DDR clock 400 MHz
CLOCK: UART clock 100000 KHz
CLOCK: MMC clock 50000 KHz
CLOCK: QSPI clock 370000 KHz
SDRAM: Initializing MMR registers
SDRAM: Calibrating PHY
SEQ.C: Preparing to start memory calibration
SEQ.C: CALIBRATION PASSED
SDRAM: 1024 MiB
SDRAM: ECC Enabled
ALTERA DWMMC: 0


U-Boot 2013.01.01 (Apr 25 2014 - 04:59:35)

CPU   : Altera SOCFPGA Platform
BOARD : Altera SOCFPGA Cyclone V Board
I2C:   ready
DRAM:  1 GiB
MMC:   ALTERA DWMMC: 0
*** Warning - bad CRC, using default environment

In:    serial
Out:   serial
Err:   serial
Net:   mii0
Hit any key to stop autoboot:  0
reading u-boot.scr
170 bytes read in 4 ms (41 KiB/s)
## Executing script at 02000000
reading opencl.rbf
3655972 bytes read in 332 ms (10.5 MiB/s)
## Starting application at 0x3FF7D4F8 ...
## Application terminated, rc = 0x0
reading zImage
3626624 bytes read in 329 ms (10.5 MiB/s)
reading socfpga.dtb
18671 bytes read in 6 ms (3 MiB/s)
## Flattened Device Tree blob at 00000100
   Booting using the fdt blob at 0x00000100
   Loading Device Tree to 03ff8000, end 03fff8ee ... OK

Starting kernel ...

Booting Linux on physical CPU 0x0
Initializing cgroup subsys cpuset
Linux version 3.13.0 (ddenisen@to-ddenisen-lv1) (gcc version 4.7.3 20121106 (prerelease) (crosstool-NG linaro-1.13.1-4.7-2012.11-20121123 - Linaro GCC 2012.11) ) #1 SMP Mon May 30 15:08:40 EDT 2016
CPU: ARMv7 Processor [413fc090] revision 0 (ARMv7), cr=10c5387d
CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
Machine model: Altera SOCFPGA Cyclone V SoC Development Kit
cma: CMA: reserved 512 MiB at 20000000
Memory policy: Data cache writealloc
PERCPU: Embedded 8 pages/cpu @80fa7000 s11264 r8192 d13312 u32768
Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 260096
Kernel command line: console=ttyS0,115200 root=/dev/mmcblk0p2 rw rootwait
PID hash table entries: 4096 (order: 2, 16384 bytes)
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Memory: 506340K/1048576K available (5382K kernel code, 259K rwdata, 1468K rodata, 367K init, 260K bss, 542236K reserved)
Virtual kernel memory layout:
    vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
    vmalloc : 0xc0800000 - 0xff000000   (1000 MB)
    lowmem  : 0x80000000 - 0xc0000000   (1024 MB)
    modules : 0x7f000000 - 0x80000000   (  16 MB)
      .text : 0x80008000 - 0x806b8a5c   (6851 kB)
      .init : 0x806b9000 - 0x80714c00   ( 367 kB)
      .data : 0x80716000 - 0x80756ef8   ( 260 kB)
       .bss : 0x80756ef8 - 0x807981b4   ( 261 kB)
SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
Hierarchical RCU implementation.
NR_IRQS:16 nr_irqs:16 16
sched_clock: 32 bits at 100MHz, resolution 10ns, wraps every 42949672950ns
Console: colour dummy device 80x30
Calibrating delay loop... 1836.64 BogoMIPS (lpj=9183232)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 512
CPU: Testing write buffer coherency: ok
ftrace: allocating 18225 entries in 54 pages
CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
Setting up static identity map for 0x4dc668 - 0x4dc6c0
CPU1: Booted secondary processor
CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
Brought up 2 CPUs
SMP: Total of 2 processors activated.
CPU: All CPU(s) started in SVC mode.
devtmpfs: initialized
VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
NET: Registered protocol family 16
fpga bridge driver
DMA: preallocated 256 KiB pool for atomic coherent allocations
L310 cache controller enabled
l2x0: 8 ways, CACHE_ID 0x410030c9, AUX_CTRL 0x32460000, Cache size: 512 kB
syscon fffef000.l2-cache: regmap [mem 0xfffef000-0xfffeffff] registered
syscon ffd05000.rstmgr: regmap [mem 0xffd05000-0xffd05fff] registered
syscon ffc25000.sdrctl: regmap [mem 0xffc25000-0xffc25fff] registered
syscon ff800000.l3regs: regmap [mem 0xff800000-0xff800fff] registered
syscon ffd08000.sysmgr: regmap [mem 0xffd08000-0xffd0bfff] registered
hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
hw-breakpoint: maximum watchpoint size is 4 bytes.
altera_hps2fpga_bridge fpgabridge.2: fpga bridge [hps2fpga] registered as device hps2fpga
altera_hps2fpga_bridge fpgabridge.2: init-val not specified
altera_hps2fpga_bridge fpgabridge.3: fpga bridge [lshps2fpga] registered as device lwhps2fpga
altera_hps2fpga_bridge fpgabridge.3: init-val not specified
altera_hps2fpga_bridge fpgabridge.4: fpga bridge [fpga2hps] registered as device fpga2hps
altera_hps2fpga_bridge fpgabridge.4: init-val not specified
bio: create slab <bio-0> at 0
FPGA Mangager framework driver
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
lcd_load_custom_fonts: i2c_master_send returns -121
lcd_cmd_no_params: i2c_master_send returns -121
lcd_cmd_one_param: i2c_master_send returns -121
lcd_cmd_no_params: i2c_master_send returns -121
lcd-comm 0-0028: LCD driver initialized
pps_core: LinuxPPS API ver. 1 registered
pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
PTP clock support registered
Switched to clocksource timer1
NET: Registered protocol family 2
TCP established hash table entries: 8192 (order: 3, 32768 bytes)
TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
TCP: Hash tables configured (established 8192 bind 8192)
TCP: reno registered
UDP hash table entries: 512 (order: 2, 16384 bytes)
UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
NET: Registered protocol family 1
RPC: Registered named UNIX socket transport module.
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
hw perfevents: enabled with ARMv7 Cortex-A9 PMU driver, 7 counters available
arm-pmu arm-pmu: PMU:CTI successfully enabled for 2 cores
NFS: Registering the id_resolver key type
Key type id_resolver registered
Key type id_legacy registered
NTFS driver 2.1.30 [Flags: R/W].
jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
msgmni has been set to 2012
io scheduler noop registered (default)
Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
ffc02000.serial0: ttyS0 at MMIO 0xffc02000 (irq = 194, base_baud = 6250000) is a 16550A
console [ttyS0] enabled
altera_fpga_manager ff706000.fpgamgr: fpga manager [Altera FPGA Manager] registered as minor 0
brd: module loaded
at24 0-0051: 4096 byte 24c32 EEPROM, writable, 32 bytes/write
cadence-qspi ff705000.spi: DMA NOT enabled
cadence-qspi ff705000.spi: master is unqueued, this is deprecated
m25p80 spi2.0: found n25q512a, expected n25q00
m25p80 spi2.0: n25q512a (65536 Kbytes)
2 ofpart partitions found on MTD device spi2.0
Creating 2 MTD partitions on "spi2.0":
0x000000000000-0x000000800000 : "Flash 0 Raw Data"
0x000000800000-0x000008000000 : "Flash 0 jffs2 Filesystem"
mtd: partition "Flash 0 jffs2 Filesystem" extends beyond the end of device "spi2.0" -- size truncated to 0x3800000
cadence-qspi ff705000.spi: Cadence QSPI controller driver
dw_spi_mmio fff00000.spi: master is unqueued, this is deprecated
CAN device driver interface
c_can_platform ffc00000.d_can: invalid resource
c_can_platform ffc00000.d_can: control memory is not used for raminit
c_can_platform ffc00000.d_can: c_can_platform device registered (regs=c08a0000, irq=163)
stmmac - user ID: 0x10, Synopsys ID: 0x37
 Ring mode enabled
 DMA HW capability register supported
 Enhanced/Alternate descriptors
        Enabled extended descriptors
 RX Checksum Offload Engine supported (type 2)
 TX Checksum insertion supported
 Enable RX Mitigation via HW Watchdog Timer
libphy: stmmac: probed
eth0: PHY ID 00221611 at 4 IRQ POLL (stmmac-0:04) active
dwc2 ffb40000.usb: unable to find phy
dwc2 ffb40000.usb: EPs:15
dwc2 ffb40000.usb: dedicated fifos
dwc2 ffb40000.usb: 2560 invalid for host_rx_fifo_size. Check HW configuration.
dwc2 ffb40000.usb: 2560 invalid for host_nperio_tx_fifo_size. Check HW configuration.
dwc2 ffb40000.usb: DWC OTG Controller
dwc2 ffb40000.usb: new USB bus registered, assigned bus number 1
dwc2 ffb40000.usb: irq 160, io mem 0x00000000
usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb1: Product: DWC OTG Controller
usb usb1: Manufacturer: Linux 3.13.0 dwc2_hsotg
usb usb1: SerialNumber: ffb40000.usb
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 1 port detected
usbcore: registered new interface driver usb-storage
mousedev: PS/2 mouse device common for all mice
rtc-ds1307 0-0068: SET TIME!
rtc-ds1307 0-0068: read error -121
rtc-ds1307 0-0068: rtc core: registered ds1339 as rtc0
i2c /dev entries driver
Synopsys Designware Multimedia Card Interface Driver
dwmmc_socfpga ff704000.dwmmc0: Using internal DMA controller.
dwmmc_socfpga ff704000.dwmmc0: Version ID is 240a
dwmmc_socfpga ff704000.dwmmc0: DW MMC controller at irq 171, 32 bit host data width, 1024 deep fifo
dwmmc_socfpga ff704000.dwmmc0: 1 slots initialized
ledtrig-cpu: registered to indicate activity on CPUs
usbcore: registered new interface driver usbhid
usbhid: USB HID core driver
oprofile: using arm/armv7-ca9
TCP: cubic registered
NET: Registered protocol family 10
sit: IPv6 over IPv4 tunneling driver
NET: Registered protocol family 17
NET: Registered protocol family 15
can: controller area network core (rev 20120528 abi 9)
NET: Registered protocol family 29
can: raw protocol (rev 20120528)
can: broadcast manager protocol (rev 20120528 t)
can: netlink gateway (rev 20130117) max_hops=1
8021q: 802.1Q VLAN Support v1.8
Key type dns_resolver registered
ThumbEE CPU extension supported.
Registering SWP/SWPB emulation handler
Waiting for root device /dev/mmcblk0p2...
mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 50000000Hz, actual 50000000HZ div = 0)
mmc0: new high speed SDHC card at address 0003
mmcblk0: mmc0:0003 SD4GB 3.67 GiB
 mmcblk0: p1 p2 p3
EXT3-fs (mmcblk0p2): error: couldn't mount because of unsupported optional features (240)
EXT2-fs (mmcblk0p2): error: couldn't mount because of unsupported optional features (240)
EXT4-fs (mmcblk0p2): warning: mounting unchecked fs, running e2fsck is recommended
EXT4-fs (mmcblk0p2): mounted filesystem without journal. Opts: (null)
VFS: Mounted root (ext4 filesystem) on device 179:2.
devtmpfs: mounted
Freeing unused kernel memory: 364K (806b9000 - 80714000)
INIT: version 2.88 booting
Starting Bootlog daemon: bootlogd.
EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Configuring network interfaces... eth0: device MAC address 00:07:ed:26:20:99
udhcpc (v1.20.2) started
Sending discover...
Sending discover...
libphy: stmmac-0:04 - Link is Up - 1000/Full
Sending discover...
Sending select for 10.162.177.237...
Lease of 10.162.177.237 obtained, lease time 86400
/etc/udhcpc.d/50default: Adding DNS 10.162.177.1
done.
Starting portmap daemon...
Wed Apr 16 05:33:00 UTC 2014
Running postinst /etc/rpm-postinsts/100...
/usr/sbin/update-modules: line 197: /etc/init.d/modutils.sh: No such file or directory
INIT: Entering runlevel: 5
Starting OpenBSD Secure Shell server: sshd
  generating ssh RSA key...
random: ssh-keygen urandom read with 89 bits of entropy available
  generating ssh ECDSA key...
  generating ssh DSA key...
done.
Starting syslogd/klogd: done
Starting Lighttpd Web Server: lighttpd.
Starting blinking LED server
lcd_cmd_no_params: i2c_master_send returns -121
lcd_cmd_one_param: i2c_master_send returns -121
lcd_cmd_one_param: i2c_master_send returns -121
lcd_cmd_one_param: i2c_master_send returns -121
Stopping Bootlog daemon: bootlogd.