Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RT patch for stable releases #2244

Closed
az2022 opened this Issue Oct 26, 2017 · 54 comments

Comments

Projects
None yet
@az2022
Copy link

az2022 commented Oct 26, 2017

With the app I work on, one of the requirement is to use Raspbian kernel with real-time patch applied. It has become an issue of finding a match to what kernel version is released by raspberry-pi org and which kernel version patch is released by kernel.org (https://www.kernel.org/pub/linux/kernel/projects/rt/). Lot of times they don't match, for e.g. I got the latest Raspbian (Stretch) which hosts kernel v4.9.41 while the real time patch is available for 4.9.40 and 4.9.47. I checked-out Raspbian source commit available right after 4.9.47 was committed to the source tree, applied RT patch and built. Everything went well and Pi3 boots fine, but sometimes hangs when apps (for e.g. gitk) are started or midway of a gcc build. Understandably Raspbian was not released with 4.9.47 but I had to try! Bottom line, it would be nice to have a RT patch available for the released/stable Rapbian images, unless there's a way around this? :)

@pelwell

This comment has been minimized.

Copy link
Contributor

pelwell commented Oct 26, 2017

Although the current Raspbian Stretch release comes with 4.9.41 there should not be any hard dependencies on a particular kernel version. The rpi-update repo hosts hundreds of kernel versions (full list available here - notice the hexadecimal numbers identifying each release), a large number of which should work with Stretch.

I suggest you use rpi-update to choose a 4.9.47 kernel:

sudo rpi-update 2663a143525df3c8305253c6f93f1707156e6a9d

Check that the kernel works (except without the RT support), then locate the corresponding point in the source tree - commit 807c5d9 ought to be OK - and apply the 4.9.47 patch.

@az2022

This comment has been minimized.

Copy link
Author

az2022 commented Oct 27, 2017

I did try your suggestion couple weeks ago and ran into issues of random sluggishness. Also when building my project it used to hang up. Today I started again from scratch with a fresh copy of Raspbian. After upgrading to v4.9.47 kernel using rpi-update, I did not see sluggishness and was able to compile my project (basically just compiling AVS device sdk from: https://github.com/alexa/avs-device-sdk/wiki/Raspberry-Pi-Quick-Start-Guide). After applying the RT patch, things still appear to work but when compiling my project again (using stock gcc) it randomly hangs in the middle, just as I saw before. After a reboot I found that some of the object files and a library were 0 bytes in size. After I removed these, I was able to complete building. If I recompile from scratch I am pretty sure it will hang again. Something is not right, which gets magnified when applying the RT patch.

@pelwell

This comment has been minimized.

Copy link
Contributor

pelwell commented Oct 27, 2017

Is the Pi perhaps running out of memory and spending all its time swapping? Check the SDK Makefile and looks for -j<n> flags that set the degree of parallelism, reducing it if it is greater than 1. You could also try running different tasks while stressing (sudo apt-get install stress) the system in different ways.

I'm happy to leave this issue open for others to see and comment on, but I'm afraid we can't support the RT patch series - we have more than enough to do with mainline Linux.

@lategoodbye

This comment has been minimized.

Copy link
Contributor

lategoodbye commented Oct 29, 2017

@az2022 Just for curiosity, what prevents you from using a mainline kernel + RT patches?

@az2022

This comment has been minimized.

Copy link
Author

az2022 commented Oct 31, 2017

@lategoodbye My Pi3 randomly hangs up.

@vanfanel

This comment has been minimized.

Copy link

vanfanel commented Nov 8, 2017

@az2022, @pelwell
The problem with RT patches on the Pi seems to be related to the FIQ exception handler that the driver of the Synopsis DWC host USB controller:

https://www.osadl.org/Single-View.111+M5c03315dc57.0.html

https://autostatic.com/2017/06/27/rpi-3-and-the-real-time-kernel/

This could be easily fixed if you guys incorporate the fix to the Pi kernel sources.

@az2022 : try these kernel parameters


dwc_otg.fiq_enable=0
dwc_otg.fiq_fsm_enable=0

and your Pi shouldn't hang when using the RT patches. It's a "workaround", not a solution. We need the kernel guys to incorporate the fix or manually apply the FIQ patch into upstream.

It's a know problem in the linux foundation:
https://wiki.linuxfoundation.org/realtime/documentation/known_limitations

Also, here are detailed instructions (not by me!) and a ready-to-use kernel:
https://isojed.nl/blog/2017/10/25/raspberry-pi-rt-preempt/

@pelwell

This comment has been minimized.

Copy link
Contributor

pelwell commented Nov 8, 2017

I presume you mean this patch?

Any comments, @P33M ?

@vanfanel

This comment has been minimized.

Copy link

vanfanel commented Nov 8, 2017

@pelwell
Yes, that's the one. There's an updated version of the patch (not totally up-to-date) here:

https://github.com/fedberry/kernel/blob/master/usb-dwc_otg-fix-system-lockup-when-interrupts-are-threaded.patch

You could easily have an RT branch... there's a lot of demand for RT kernels on the Raspberry, and finding matching RT patches is not easy.
Of course you only would update that branch when there's a new stable release.

@P33M

This comment has been minimized.

Copy link
Contributor

P33M commented Nov 9, 2017

Currently the FIQ lock is held only within the IRQ handler, which implies no other IRQs can preempt the dwc_otg interrupt and the driver-specific spinlock is held. I suppose that adding a "real" IRQ save/restore would be harmless in the non-RT case.

The latency graph on the autostatic.com site is interesting. If the upper bound for latency is 75uS then this approaches the required hard-realtime horizon for some of the USB usecases - high-speed Isochronous transfers in particular. We know that even with the FIQ helping, it's possible to miss scheduling isochronous transfers at the boundary of every URB as this requires manipulating software queues. If RT makes this problem go away, then it'd be an interesting avenue to explore.

@vanfanel

This comment has been minimized.

Copy link

vanfanel commented Nov 9, 2017

@P33M: Would that improve USB HID input latency?

@P33M

This comment has been minimized.

Copy link
Contributor

P33M commented Nov 9, 2017

No. The dwc_otg driver doesn't know about scheduling constraints higher up in the USB stack.

By default we restrict HID mouse polling to 60Hz to reduce the Xserver load on BCM2835-based devices, so setting usbhid.mousepoll=0 in cmdline.txt will restore the default polling interval.

@vanfanel

This comment has been minimized.

Copy link

vanfanel commented Nov 9, 2017

@P33M
Do you only restrict polling rate for mouse, or for usb joysticks too? What is the default polling rate for usb joysticks in Raspbian kernel on the current versions? Isn't it 120Hz as in mainline kernels?

Also, a basic question I have been asking myself these days, and maybe you can answer because I can't find the information: usb joysticks and mice are accessed through the modern evdev interface in all low-latency APIs available on the Pi, like SDL2 and LibRetro/RetroArch. They all use evded. (X11 is not important for this matter).
Well, evdev is an event-driven interface: it's main objetive is precissely to avoid the old, CPU-consuming and unefficient polling techniques. So:
How is the kernel polling rate (usbhid.jspoll, usbhid.mousepoll) related to evdev then?
I don't get it, and you can be sure I have searched for an answer low and high...

@az2022

This comment has been minimized.

Copy link
Author

az2022 commented Nov 9, 2017

@vanfanel Spot on. For a quick check I applied the command line arguments and I have not been able to reproduce the problem for 2+ hours now, which is very encouraging! Will leave it for over night test.
BTW, since these are OTG related arguments, I imagine folks who don't have USB devices connected to their Pi3 may not see this issue?

@nettings

This comment has been minimized.

Copy link

nettings commented Nov 11, 2017

I'd be interested in "RT-ready" RPi kernels, too. Running https://autostatic.com/2017/06/27/rpi-3-and-the-real-time-kernel/ for a few projects now, and currently trying to update to the latest 4.9-rt. It would be a huge help if the lockup workaround was in RPi-linux mainline if it doesn't harm the common usecases (or is even beneficial). Willing to test...

@az2022

This comment has been minimized.

Copy link
Author

az2022 commented Nov 15, 2017

Setting kernel paramaters, dwc_otg.fiq_enable=0, dwc_otg.fiq_fsm_enable=0 works well with both keyboard and mice but after some testing noticed it made my USB mic unusable. Applied the usb-fiq patch and rebuilt, USB mic now works.

@nettings

This comment has been minimized.

Copy link

nettings commented Nov 15, 2017

I'm just building a kernel from 4.9.61 (current HEAD) with https://www.kernel.org/pub/linux/kernel/projects/rt/4.9/patch-4.9.47-rt37.patch.gz and https://github.com/fedberry/kernel/blob/master/usb-dwc_otg-fix-system-lockup-when-interrupts-are-threaded.patch. All NEW options with default answer, full preemption, HZ=1000, one implicit declaration error (removed -Werror-implicit-function-declaration for now). Seems to compile, will test tomorrow.

Update: this attempt did not work. Sorry for getting back to this so late...

@JamesH65

This comment has been minimized.

Copy link
Contributor

JamesH65 commented Dec 5, 2017

What is the current status of this issue? Should it be closed?

@nettings

This comment has been minimized.

Copy link

nettings commented Dec 5, 2017

Maybe we should open another issue requesting that just the FIQ patch is merged into RPi mainline? So that the RT patch can be applied out-of-the-box....

@az2022

This comment has been minimized.

Copy link
Author

az2022 commented Jan 13, 2018

Sorry about the delayed response. Perhaps the issue could be well published/documented where users could immediately notice and choose whether to apply the USB patch or not. For a long term solution a RT ready image with the USB patch would be nice, but I understand the resource shortage as well.

@markusr

This comment has been minimized.

Copy link

markusr commented Jan 25, 2018

I got a recent RT kernel running on a Raspi 3.

pi@raspberrypi:~/rt/rt-tests $ uname -a
Linux raspberrypi 4.14.14-rt10-v7 #1 SMP PREEMPT RT Thu Jan 25 14:08:05 UTC 2018 armv7l GNU/Linux

I adapted the instructions from here: http://ffall007.16mb.com/post/applying-preempt-rt-kernel-patch-on-raspberry-pi/

  1. Download kernel source and extract.
wget https://github.com/raspberrypi/linux/archive/23816e63fcc5efa8400f248304db13d5df69792f.zip

I could not compile a later version, because of this patch:
2f77f72
which is not compatible with the patch-4.14.12-rt10.patch

  1. Download RT patch
wget https://www.kernel.org/pub/linux/kernel/projects/rt/4.14/patch-4.14.12-rt10.patch.gz
  1. Apply RT patch
zcat ../patch-4.14.12-rt10.patch.gz | patch -p1

Then follow the "normal" compilation and installation instructions for a RT kernel.

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Feb 23, 2018

I'd like to introduce -rt branch, and I'm planning to maintain this as well.

https://github.com/TiejunChina/linux/tree/rpi-4.14.y-rt

This is based on rpi-4.14.y but with the latest v4.14.20-rt17. This can boot on pi3,

$ uname -a
Linux linux.suse 4.14.20-rt17-v8+ #1 SMP PREEMPT RT Fri Feb 23 13:19:32 CST 2018 aarch64 aarch64 aarch64 GNU/Linux

I also did cyclictest as well.

@pelwell , You know, we also had a little bit of discussion on this previously. Please let me know how to put this into official raspberrypi/linux.

@pelwell

This comment has been minimized.

Copy link
Contributor

pelwell commented Mar 1, 2018

The first Raspberry Pi PREEMPT_RT kernel branch went live this morning: https://github.com/raspberrypi/linux/tree/rpi-4.14.y-rt

Thank you for your efforts and continuing support, @TiejunChina.

@nettings

This comment has been minimized.

Copy link

nettings commented Mar 1, 2018

Amazing! Thanks to all contributors! Can't wait to try this one out.

@paul-1

This comment has been minimized.

Copy link

paul-1 commented Mar 1, 2018

Thanks for maintaining this, will save me some patching time.

Out of curiosity, have you been able to run this on an armv6 device, with FIQ enabled? It will run with FIQ disabled, but suffers from all of the pre-fiq usb problems.

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Mar 2, 2018

@paul-1 Sorry, I have no armv6 device in my hand. I will try to get access to that later. But now, what is that problem? Is that a lockup issue?

@paul-1

This comment has been minimized.

Copy link

paul-1 commented Mar 2, 2018

Just hangs during boot. There are no kernel panics/oops.

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Mar 2, 2018

@paul-1 Would like to try this branch?

@T-vK

This comment has been minimized.

Copy link

T-vK commented Mar 5, 2018

@TiejunChina I've been trying to build a working kernel out of your branch for over a week now. But I just can't get it to boot properly. I have posted more details in this forum thread, it would be nice if you could take a look at it: https://www.raspberrypi.org/forums/viewtopic.php?f=71&t=205604&p=1281396&sid=add236ca46e8f3ca05b9614a56f374d1#p1281396

@pelwell

This comment has been minimized.

Copy link
Contributor

pelwell commented Mar 5, 2018

It's on my list to look at - probably this afternoon.

@pelwell

This comment has been minimized.

Copy link
Contributor

pelwell commented Mar 5, 2018

Try adding dtoverlay=dwc2 to config.txt. FIQ support is compromised in some way on the -rt branch.

@soundchekk

This comment has been minimized.

Copy link

soundchekk commented Mar 12, 2018

I just compiled the latest git rt-kernel branch. (I've been maintaining rt-kernels for Moode-Audio for a while)

dwc_otg related cmdline.txt options are:
dwc_otg.fiq_fsm_enable=0 dwc_otg.fiq_enable=0 dwc_otg.nak_holdoff=0

cyclictest looks OK:
T: 0 ( 334) P:80 I:500 C: 100000 Min: 8 Act: 12 Avg: 11 Max: 28

However. The old and known dwc_otg load up2 as seen below 11.2% issue
during idle operation still exists:

149 root -51 0 0 0 0 R 11.2 0.0 1:05.54 irq/39-dwc2_hso
144 root -51 0 0 0 0 S 9.9 0.0 0:58.50 irq/39-3f980000
148 root -51 0 0 0 0 S 7.3 0.0 0:46.11 irq/39-3f980000

As you can see I also tried the dwc2 overlay as suggested by pelwell.

Any ideas how to approach the subject?

@soundchekk

This comment has been minimized.

Copy link

soundchekk commented Mar 12, 2018

One more:

I forgot. I'm talking about:
kernel 4.14.24-rt19
and I run a ArchLinux Arm system.

Below the loads with the dwc2 overlay removed again.

80 root -51 0 0 0 0 S 11.8 0.0 0:23.99 irq/39-dwc_otg_
78 root -51 0 0 0 0 S 10.5 0.0 0:20.69 irq/39-dwc_otg
79 root -51 0 0 0 0 S 7.6 0.0 0:15.63 irq/39-dwc_otg_

I also tried to remove dwc_otg options from cmdline.txt. - now with the new kernel in place.
After that the PI wouldn't boot properly anymore.

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Mar 13, 2018

@soundchekk I think you should first check if you rpi is always receiving irq/39-dwc_otg, like cat /proc/interrupts without enabling -rt Kconfig. If this is sort of irq/39-dwc_otg storm, that associated irq to irq/39-dwc_otg would spike cpu as a certain percentage in the case of -rt. If yes, this is expected, and not a real problem to -rt case.

@soundchekk

This comment has been minimized.

Copy link

soundchekk commented Mar 13, 2018

I did some more testing.
Standard kernel: 4.14.24-1-ARCH

TC1:
cmdline.txt
"dwc_otg.fiq_fsm_enable=0 dwc_otg.fiq_enable=0 dwc_otg.nak_holdoff=0"

Average dwc_otg interrupts: 8164 /s
CPU load: "0"

TC2:
cmdline.txt
"default dwc_otg - all options from TC1 taken out"

Average dwc_otg interrupts: 274 /s
CPU load: "0"

########
rt-kernel: 4.14.24-rt19-sc1 - default config
#########
TC3:
cmdline.txt
"dwc_otg.fiq_fsm_enable=0 dwc_otg.fiq_enable=0 dwc_otg.nak_holdoff=0"

Average dwc_otg interrupts: 8244 /s
CPU load: "12%"

TC4:
cmdline.txt
"default dwc_otg - all options from TC3 taken out"

Average dwc_otg interrupts: X /s
CPU load: "X"

Testcase TC4 failed because lock-up at boot! Lock-up occurs during printout of USB init messages.

##################

Bottom line.
The number of interrupts "normal vs. rt-kernel" are pretty much identical.
The FIQ... enable=0 params causing a hell of an IRQ load. 30 times higher. On both kernels.
The CPU impact of these high number of interrupts is quite a different one.
At least on my setup the rt-kernel caused CPU load isn't looking OK.

Still. Don't know yet why my setup locks up (around USB dev init) when booting TC4.

@

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Mar 19, 2018

@soundchekk Sorry for this delay response.

Could you try the latest rpi-4.14.y-rt? I validated this on my side with pi3 mode B where I preinstalled ubuntu mate 16.04.2. I think your TC4 should work now.

@soundchekk

This comment has been minimized.

Copy link

soundchekk commented Mar 19, 2018

with 4.14.27-rt19-sc1

TC5:

  • kernel boots with FIQ on
  • dwc_otg load: 0.3-0.7%
  • dwc_otg interrupts: 278/s (still seems quite high)

Perhaps you should have merged latest 4.14.27-rt21 patch.

Thx for looking into it.

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Mar 19, 2018

@soundchekk Yes, I'm working on merging -rt21. I'm always curious why we have so many interrupts even in the case of none-rt. You know, that means threaded irq always spikes on CPU for a while, as you obverse.

@andreasBihlmaier

This comment has been minimized.

Copy link

andreasBihlmaier commented Mar 28, 2018

After many years of handcrafting RT kernels for Pi, even just for "normal" use cases, I might finally be able to let go of this occupation :)
Big thank you to @TiejunChina!

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Apr 1, 2018

@andreasBihlmaier Thanks. We are still working on some known issues but any contributions are welcome.

@jarodsmith

This comment has been minimized.

Copy link

jarodsmith commented Apr 1, 2018

Dear all,

I have been trying for days to build and boot this real time kernel on a Pi Zero W.

However... I'm running into a strange problem during boot. When it gets to systemd, it kind of hangs. I mean it takes about 30 seconds to move to the next boot step as you can see in the attached boot log below. It goes on like this for a while (every 30 seconds a new message line) and in the end it just hangs...
I have tried to google this behaviour to no avail...

If anyone has any idea what might cause this, please let me know.

These are my cmdline and config files...

Thank you in advance,
Jarod


cmdline.txt


dwc_otg.lpm_enable=0 console=tty1 console=serial0,115200 root=PARTUUID=cb4a1ae3-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait dwc_otg.fiq_fsm_enable=0 dwc_otg.fiq_enable=0 dwc_otg.nak_holdoff=0


config.txt


avoid_safe_mode=1
dtparam=i2c_arm=on
dtparam=spi=on
enable_uart=1

dtparam=i2c1_baudrate=400000
dtoverlay=mcp2515-can3
dtoverlay=dwc2


Boot log


[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.14.22-rt17+ (ja@ubuntu) (gcc version 4.8.3 20140303 (prerelease) (crosstool-NG linaro-1.13.1+bzr2650 - Linaro GCC 2014.03)) #1
PREEMPT RT Sun Apr 1 13:27:00 CEST 2018
[ 0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[ 0.000000] OF: fdt: Machine model: Raspberry Pi Zero W Rev 1.1
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] cma: Reserved 8 MiB at 0x1b400000
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 113680
[ 0.000000] Kernel command line: 8250.nr_uarts=1 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 smsc95xx.macaddr=B8:27:EB:1D:65:20 vc_mem
.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 ignore_log_level dwc_otg.lpm_enable=0 console=tty1 console=ttyS0,115200 root=PARTUUID=cb4a1ae3-02 rootfstype=ex
t4 elevator=deadline fsck.repair=yes rootwait dwc_otg.fiq_fsm_enable=0 dwc_otg.fiq_enable=0 dwc_otg.nak_holdoff=0
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Memory: 435104K/458752K available (6552K kernel code, 570K rwdata, 1996K rodata, 444K init, 700K bss, 15456K reserved, 8192K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0xdc800000 - 0xff800000 ( 560 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xdc000000 ( 448 MB)
[ 0.000000] modules : 0xbf000000 - 0xc0000000 ( 16 MB)
[ 0.000000] .text : 0xc0008000 - 0xc066e4cc (6554 kB)
[ 0.000000] .init : 0xc08ed000 - 0xc095c000 ( 444 kB)
[ 0.000000] .data : 0xc095c000 - 0xc09eab24 ( 571 kB)
[ 0.000000] .bss : 0xc09f072c - 0xc0a9fb04 ( 701 kB)
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] ftrace: allocating 23966 entries in 71 pages
[ 0.000000] Preemptible hierarchical RCU implementation.
[ 0.000000] No expedited grace period (rcu_normal_after_boot).
[ 0.000000] Tasks RCU enabled.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000030] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[ 0.000056] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[ 0.000147] bcm2835: system timer (irq = 27)
[ 0.000721] Console: colour dummy device 80x30
[ 0.001866] console [tty1] enabled
[ 0.001912] Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792)
[ 0.060322] pid_max: default: 32768 minimum: 301
[ 0.060834] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.060849] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.062183] Disabling memory control group subsystem
[ 0.062362] CPU: Testing write buffer coherency: ok
[ 0.063789] Setting up static identity map for 0x8200 - 0x8238
[ 0.064538] Hierarchical SRCU implementation.
[ 0.066908] devtmpfs: initialized
[ 0.080313] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
[ 0.081092] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.081192] futex hash table entries: 256 (order: 1, 8192 bytes)
[ 0.082686] pinctrl core: initialized pinctrl subsystem
[ 0.084518] NET: Registered protocol family 16
[ 0.087851] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.096227] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[ 0.096315] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.096499] Serial: AMBA PL011 UART driver
[ 0.100198] bcm2835-mbox 2000b880.mailbox: mailbox enabled
[ 0.101383] uart-pl011 20201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[ 0.153421] bcm2835-dma 20007000.dma: DMA legacy API manager at dc80d00, dmachans=0x1
[ 0.156233] SCSI subsystem initialized
[ 0.156597] usbcore: registered new interface driver usbfs
[ 0.156767] usbcore: registered new interface driver hub
[ 0.157140] usbcore: registered new device driver usb
[ 0.161523] raspberrypi-firmware soc:firmware: Attached to firmware from 2018-03-23 16:31
[ 0.164334] clocksource: Switched to clocksource timer
[ 0.274164] VFS: Disk quotas dquot_6.6.0
[ 0.274551] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.275105] FS-Cache: Loaded
[ 0.275537] CacheFiles: Loaded
[ 0.297833] NET: Registered protocol family 2
[ 0.299367] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.299545] TCP bind hash table entries: 4096 (order: 4, 98304 bytes)
[ 0.299907] TCP: Hash tables configured (established 4096 bind 4096)
[ 0.300133] UDP hash table entries: 256 (order: 2, 16384 bytes)
[ 0.300251] UDP-Lite hash table entries: 256 (order: 2, 16384 bytes)
[ 0.300781] NET: Registered protocol family 1
[ 0.301880] RPC: Registered named UNIX socket transport module.
[ 0.301952] RPC: Registered udp transport module.
[ 0.301990] RPC: Registered tcp transport module.
[ 0.302026] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.304873] hw perfevents: no irqs for PMU, sampling events not supported
[ 0.305029] hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available
[ 0.310552] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[ 0.326458] FS-Cache: Netfs 'nfs' registered for caching
[ 0.327947] NFS: Registering the id_resolver key type
[ 0.328077] Key type id_resolver registered
[ 0.328122] Key type id_legacy registered
[ 0.334079] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 0.334886] io scheduler noop registered
[ 0.334954] io scheduler deadline registered (default)
[ 0.335393] io scheduler cfq registered
[ 0.335451] io scheduler mq-deadline registered
[ 0.335492] io scheduler kyber registered
[ 0.338316] BCM2708FB: allocated DMA memory 5b500000
[ 0.338855] BCM2708FB: allocated DMA channel 0 @ dc80d00
[ 0.347573] Console: switching to colour frame buffer device 82x26
[ 0.357038] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[ 0.362928] bcm2835-rng 20104000.rng: hwrng registered
[ 0.366307] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
[ 0.372831] vc-sm: Videocore shared memory driver
[ 0.376813] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
[ 0.405531] brd: module loaded
[ 0.424945] loop: module loaded
[ 0.427627] Loading iSCSI transport class v2.0-870.
[ 0.431395] usbcore: registered new interface driver smsc95xx
[ 0.434129] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.666746] Core Release: 2.80a
[ 0.669395] Setting default values for core params
[ 0.671992] Finished setting default values for core params
[ 0.876661] Using Buffer DMA mode
[ 0.879416] Periodic Transfer Interrupt Enhancement - disabled
[ 0.882206] Multiprocessor Interrupt Enhancement - disabled
[ 0.885158] OTG VER PARAM: 0, OTG VER FLAG: 0
[ 0.887998] Dedicated Tx FIFOs mode
[ 0.891784] dwc_otg 20980000.usb: DWC OTG Controller
[ 0.894954] dwc_otg 20980000.usb: new USB bus registered, assigned bus number 1
[ 0.898218] dwc_otg 20980000.usb: irq 33, io mem 0x00000000
[ 0.901041] Init: Port Power? op_state=1
[ 0.903644] Init: Power Port (0)
[ 0.906935] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.909588] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.912147] usb usb1: Product: DWC OTG Controller
[ 0.914856] usb usb1: Manufacturer: Linux 4.14.22-rt17+ dwc_otg_hcd
[ 0.917523] usb usb1: SerialNumber: 20980000.usb
[ 0.921541] hub 1-0:1.0: USB hub found
[ 0.924275] hub 1-0:1.0: 1 port detected
[ 0.929280] usbcore: registered new interface driver usb-storage
[ 0.932447] mousedev: PS/2 mouse device common for all mice
[ 0.935467] IR NEC protocol handler initialized
[ 0.938025] IR RC5(x/sz) protocol handler initialized
[ 0.940496] IR RC6 protocol handler initialized
[ 0.942954] IR JVC protocol handler initialized
[ 0.945615] IR Sony protocol handler initialized
[ 0.947985] IR SANYO protocol handler initialized
[ 0.950342] IR Sharp protocol handler initialized
[ 0.952611] IR MCE Keyboard/mouse protocol handler initialized
[ 0.955141] IR XMP protocol handler initialized
[ 0.958965] bcm2835-wdt 20100000.watchdog: Broadcom BCM2835 watchdog timer
[ 0.962232] bcm2835-cpufreq: min=700000 max=1000000
[ 0.965849] sdhci: Secure Digital Host Controller Interface driver
[ 0.968349] sdhci: Copyright(c) Pierre Ossman
[ 0.971793] mmc-bcm2835 20300000.mmc: could not get clk, deferring probe
[ 0.975597] sdhost-bcm2835 20202000.mmc: could not get clk, deferring probe
[ 0.978467] sdhci-pltfm: SDHCI platform and OF driver helper
[ 0.981847] hidraw: raw HID events driver (C) Jiri Kosina
[ 0.984938] usbcore: registered new interface driver usbhid
[ 0.987566] usbhid: USB HID core driver
[ 0.990966] vchiq: vchiq_init_state: slot_zero = db580000, is_master = 0
[ 0.996319] [vc_sm_connected_init]: start
[ 1.007243] [vc_sm_connected_init]: end - returning 0
[ 1.011340] Initializing XFRM netlink socket
[ 1.014061] NET: Registered protocol family 17
[ 1.017112] Key type dns_resolver registered
[ 1.022011] registered taskstats version 1
[ 1.037971] uart-pl011 20201000.serial: cts_event_workaround enabled
[ 1.040993] 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2
[ 1.050917] console [ttyS0] disabled
[ 1.053850] 20215040.serial: ttyS0 at MMIO 0x0 (irq = 160, base_baud = 31250000) is a 16550
[ 1.970460] console [ttyS0] enabled
[ 1.979194] Indeed it is in host mode hprt0 = 00021501
[ 1.984822] mmc-bcm2835 20300000.mmc: mmc_debug:0 mmc_debug2:0
[ 1.984834] mmc-bcm2835 20300000.mmc: DMA channel allocated
[ 2.064910] sdhost: log_buf @ db513000 (5b513000)
[ 2.118295] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[ 2.128751] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 2.139413] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 2.151026] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[ 2.164559] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[ 2.175314] of_cfs_init
[ 2.180436] of_cfs_init: OK
[ 2.809073] irq 53: nobody cared (try booting with the "irqpoll" option)
[ 2.809092] CPU: 0 PID: 56 Comm: irq/53-bcm2835- Not tainted 4.14.22-rt17+ #1
[ 2.809097] Hardware name: BCM2835
[ 2.809165] [] (unwind_backtrace) from [] (show_stack+0x20/0x24)
[ 2.809201] [] (show_stack) from [] (dump_stack+0x20/0x28)
[ 2.809229] [] (dump_stack) from [] (__report_bad_irq+0x34/0x140)
[ 2.809247] [] (__report_bad_irq) from [] (note_interrupt+0x254/0x2b4)
[ 2.809264] [] (note_interrupt) from [] (handle_irq_event_percpu+0x78/0x90)
[ 2.809280] [] (handle_irq_event_percpu) from [] (handle_irq_event+0x5c/0xa0)
[ 2.809298] [] (handle_irq_event) from [] (handle_level_irq+0xb8/0x170)
[ 2.809315] [] (handle_level_irq) from [] (generic_handle_irq+0x30/0x44)
[ 2.809330] [] (generic_handle_irq) from [] (__handle_domain_irq+0x6c/0xe0)
[ 2.809346] [] (__handle_domain_irq) from [] (bcm2835_handle_irq+0x28/0x48)
[ 2.809373] [] (bcm2835_handle_irq) from [] (__irq_svc+0x5c/0xa8)
[ 2.809381] Exception stack(0xda523eb8 to 0xda523f00)
[ 2.809390] 3ea0: 00000000 00000001
[ 2.809404] 3ec0: 00400000 c0961c54 dac28900 da4f0580 da522000 dac28910 c0069da0 c09e7472
[ 2.809418] 3ee0: dadb9c7c da523f24 da523f08 da523f08 c0069c58 c0069c5c 40000113 ffffffff
[ 2.809438] [] (__irq_svc) from [] (irq_finalize_oneshot+0x8c/0x18c)
[ 2.809454] [] (irq_finalize_oneshot) from [] (irq_forced_thread_fn+0x40/0x64)
[ 2.809469] [] (irq_forced_thread_fn) from [] (irq_thread+0x108/0x1fc)
[ 2.809499] [] (irq_thread) from [] (kthread+0x124/0x160)
[ 2.809523] [] (kthread) from [] (ret_from_fork+0x14/0x20)
[ 2.809528] handlers:
[ 2.809539] [] irq_default_primary_handler threaded [] bcm2835_auxirq_handler
[ 2.809570] Disabling IRQ #53
[ 2.809876] usb 1-1: new high-speed USB device number 2 using dwc_otg
[ 2.819188] Waiting for root device PARTUUID=cb4a1ae3-02...
[ 2.915959] mmc1: new high speed SDIO card at address 0001
[ 2.986364] mmc0: host does not support reading read-only switch, assuming write-enable
[ 2.989834] mmc0: new high speed SDHC card at address aaaa
[ 2.994608] mmcblk0: mmc0:aaaa SB16G 14.8 GiB
[ 2.998042] mmcblk0: p1 p2
[ 3.046890] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 3.046999] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 3.051134] devtmpfs: mounted
[ 3.053806] Freeing unused kernel memory: 444K
[ 3.053814] This architecture does not have kernel memory protection.
[ 3.466830] Indeed it is in host mode hprt0 = 00001101
[ 3.616813] systemd[1]: System time before build time, advancing clock.
[ 3.752639] usb 1-1: New USB device found, idVendor=05ac, idProduct=1402
[ 3.770876] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3.790800] usb 1-1: Product: Apple USB Ethernet Adapter
[ 3.808881] usb 1-1: Manufacturer: Apple Inc.
[ 3.819660] NET: Registered protocol family 10
[ 3.831180] usb 1-1: SerialNumber: 2421EF
[ 3.835755] Segment Routing with IPv6
[ 3.858664] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 3.928065] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +
XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[ 3.956827] systemd[1]: Detected architecture arm.
[ 34.408916] systemd[1]: Set hostname to .
[ 65.766905] systemd[1]: Listening on udev Kernel Socket.
[ 95.846646] systemd[1]: Created slice User and Session Slice.
[ 125.925503] systemd[1]: Listening on Syslog Socket.
[ 156.006438] systemd[1]: Created slice System Slice.
[ 186.091972] systemd[1]: Mounting Debug File System...
[ 216.165308] systemd[1]: Listening on fsck to fsckd communication Socket.
[ 246.245789] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ 276.325615] systemd[1]: Listening on udev Control Socket.
[ 306.405821] systemd[1]: Listening on Journal Socket.
[ 336.499758] systemd[1]: Starting Load Kernel Modules...
[ 336.596052] i2c /dev entries driver
[ 366.572123] systemd[1]: Starting Set the console keyboard layout...
[ 396.679466] systemd[1]: Starting File System Check on Root Device...
[ 426.732055] systemd[1]: Mounting RPC Pipe File System...
[ 486.885350] systemd[1]: Listening on Journal Socket (/dev/log).
[ 516.966744] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[ 547.046624] systemd[1]: Created slice system-serial\x2dgetty.slice.

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Apr 1, 2018

@jarodsmith Before we take a close look at your issue, please use the latest -rt branch version. Your -rt version is 4.14.22-rt17 is sort of outdated.

@jarodsmith

This comment has been minimized.

Copy link

jarodsmith commented Apr 1, 2018

Thank you for the answer. I have cloned and built the latest branch 4.14.31-rt25+

I get exactly the same behaviour... Please see boot log below.

I would really appreciate it if you could help with this.

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.14.31-rt25+ (ja@ubuntu) (gcc version 4.8.3 20140303 (prerelease) (crosstool-NG linaro-1.13.1+bzr2650 - Linaro GCC 2014.03)) #1
PREEMPT RT Sun Apr 1 20:25:01 CEST 2018
[ 0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[ 0.000000] OF: fdt: Machine model: Raspberry Pi Zero W Rev 1.1
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] cma: Reserved 8 MiB at 0x1b400000
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 113680
[ 0.000000] Kernel command line: 8250.nr_uarts=1 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 smsc95xx.macaddr=B8:27:EB:1D:65:20 vc_mem
.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 ignore_log_level dwc_otg.lpm_enable=0 console=tty1 console=ttyS0,115200 root=PARTUUID=cb4a1ae3-02 rootfstype=ex
t4 elevator=deadline fsck.repair=yes rootwait dwc_otg.fiq_fsm_enable=0 dwc_otg.fiq_enable=0 dwc_otg.nak_holdoff=0
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Memory: 434960K/458752K available (6643K kernel code, 595K rwdata, 2020K rodata, 440K init, 701K bss, 15600K reserved, 8192K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0xdc800000 - 0xff800000 ( 560 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xdc000000 ( 448 MB)
[ 0.000000] modules : 0xbf000000 - 0xc0000000 ( 16 MB)
[ 0.000000] .text : 0xc0008000 - 0xc068500c (6645 kB)
[ 0.000000] .init : 0xc090c000 - 0xc097a000 ( 440 kB)
[ 0.000000] .data : 0xc097a000 - 0xc0a0ef54 ( 596 kB)
[ 0.000000] .bss : 0xc0a14b80 - 0xc0ac3fdc ( 702 kB)
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] ftrace: allocating 24294 entries in 72 pages
[ 0.000000] Preemptible hierarchical RCU implementation.
[ 0.000000] No expedited grace period (rcu_normal_after_boot).
[ 0.000000] Tasks RCU enabled.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000033] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[ 0.000059] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[ 0.000149] bcm2835: system timer (irq = 27)
[ 0.000724] Console: colour dummy device 80x30
[ 0.001846] console [tty1] enabled
[ 0.001893] Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792)
[ 0.060326] pid_max: default: 32768 minimum: 301
[ 0.060835] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.060851] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.062185] Disabling memory control group subsystem
[ 0.062359] CPU: Testing write buffer coherency: ok
[ 0.063783] Setting up static identity map for 0x8200 - 0x8238
[ 0.070478] Hierarchical SRCU implementation.
[ 0.072918] devtmpfs: initialized
[ 0.087674] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
[ 0.088308] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.088411] futex hash table entries: 256 (order: 1, 8192 bytes)
[ 0.089913] pinctrl core: initialized pinctrl subsystem
[ 0.092037] NET: Registered protocol family 16
[ 0.095425] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.104783] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[ 0.104870] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.105054] Serial: AMBA PL011 UART driver
[ 0.108833] bcm2835-mbox 2000b880.mailbox: mailbox enabled
[ 0.109833] uart-pl011 20201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[ 0.165995] bcm2835-dma 20007000.dma: DMA legacy API manager at dc80d00, dmachans=0x1
[ 0.168911] SCSI subsystem initialized
[ 0.169286] usbcore: registered new interface driver usbfs
[ 0.169465] usbcore: registered new interface driver hub
[ 0.169844] usbcore: registered new device driver usb
[ 0.171580] raspberrypi-firmware soc:firmware: Attached to firmware from 2018-03-23 16:31
[ 0.174502] clocksource: Switched to clocksource timer
[ 0.291986] VFS: Disk quotas dquot_6.6.0
[ 0.292180] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.292710] FS-Cache: Loaded
[ 0.293147] CacheFiles: Loaded
[ 0.316291] NET: Registered protocol family 2
[ 0.317854] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.318034] TCP bind hash table entries: 4096 (order: 4, 98304 bytes)
[ 0.318397] TCP: Hash tables configured (established 4096 bind 4096)
[ 0.318625] UDP hash table entries: 256 (order: 2, 16384 bytes)
[ 0.318743] UDP-Lite hash table entries: 256 (order: 2, 16384 bytes)
[ 0.319274] NET: Registered protocol family 1
[ 0.320379] RPC: Registered named UNIX socket transport module.
[ 0.320455] RPC: Registered udp transport module.
[ 0.320494] RPC: Registered tcp transport module.
[ 0.320529] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.323170] hw perfevents: no irqs for PMU, sampling events not supported
[ 0.323317] hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available
[ 0.329229] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[ 0.347493] FS-Cache: Netfs 'nfs' registered for caching
[ 0.349350] NFS: Registering the id_resolver key type
[ 0.349469] Key type id_resolver registered
[ 0.349515] Key type id_legacy registered
[ 0.349577] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.356051] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 0.356585] io scheduler noop registered
[ 0.356652] io scheduler deadline registered (default)
[ 0.357102] io scheduler cfq registered
[ 0.357161] io scheduler mq-deadline registered
[ 0.357201] io scheduler kyber registered
[ 0.360006] BCM2708FB: allocated DMA memory 5b500000
[ 0.360554] BCM2708FB: allocated DMA channel 0 @ dc80d00
[ 0.369273] Console: switching to colour frame buffer device 82x26
[ 0.379057] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[ 0.385336] bcm2835-rng 20104000.rng: hwrng registered
[ 0.388330] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
[ 0.395309] vc-sm: Videocore shared memory driver
[ 0.398775] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
[ 0.428471] brd: module loaded
[ 0.448485] loop: module loaded
[ 0.451184] Loading iSCSI transport class v2.0-870.
[ 0.455239] usbcore: registered new interface driver smsc95xx
[ 0.457980] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.690278] Core Release: 2.80a
[ 0.692916] Setting default values for core params
[ 0.695751] Finished setting default values for core params
[ 0.900276] Using Buffer DMA mode
[ 0.903001] Periodic Transfer Interrupt Enhancement - disabled
[ 0.905934] Multiprocessor Interrupt Enhancement - disabled
[ 0.908726] OTG VER PARAM: 0, OTG VER FLAG: 0
[ 0.911533] Dedicated Tx FIFOs mode
[ 0.915495] dwc_otg 20980000.usb: DWC OTG Controller
[ 0.918422] dwc_otg 20980000.usb: new USB bus registered, assigned bus number 1
[ 0.921646] dwc_otg 20980000.usb: irq 33, io mem 0x00000000
[ 0.924466] Init: Port Power? op_state=1
[ 0.927249] Init: Power Port (0)
[ 0.930407] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.933022] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.935710] usb usb1: Product: DWC OTG Controller
[ 0.938254] usb usb1: Manufacturer: Linux 4.14.31-rt25+ dwc_otg_hcd
[ 0.940884] usb usb1: SerialNumber: 20980000.usb
[ 0.945172] hub 1-0:1.0: USB hub found
[ 0.947960] hub 1-0:1.0: 1 port detected
[ 0.952625] usbcore: registered new interface driver usb-storage
[ 0.956117] mousedev: PS/2 mouse device common for all mice
[ 0.958808] IR NEC protocol handler initialized
[ 0.961336] IR RC5(x/sz) protocol handler initialized
[ 0.963840] IR RC6 protocol handler initialized
[ 0.966576] IR JVC protocol handler initialized
[ 0.968924] IR Sony protocol handler initialized
[ 0.971261] IR SANYO protocol handler initialized
[ 0.973592] IR Sharp protocol handler initialized
[ 0.976111] IR MCE Keyboard/mouse protocol handler initialized
[ 0.978422] IR XMP protocol handler initialized
[ 0.982296] bcm2835-wdt 20100000.watchdog: Broadcom BCM2835 watchdog timer
[ 0.985848] bcm2835-cpufreq: min=700000 max=1000000
[ 0.989244] sdhci: Secure Digital Host Controller Interface driver
[ 0.991737] sdhci: Copyright(c) Pierre Ossman
[ 0.995382] mmc-bcm2835 20300000.mmc: could not get clk, deferring probe
[ 0.999047] sdhost-bcm2835 20202000.mmc: could not get clk, deferring probe
[ 1.001871] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.005458] hidraw: raw HID events driver (C) Jiri Kosina
[ 1.008394] usbcore: registered new interface driver usbhid
[ 1.011016] usbhid: USB HID core driver
[ 1.014455] vchiq: vchiq_init_state: slot_zero = db580000, is_master = 0
[ 1.019739] [vc_sm_connected_init]: start
[ 1.030498] [vc_sm_connected_init]: end - returning 0
[ 1.034761] Initializing XFRM netlink socket
[ 1.037508] NET: Registered protocol family 17
[ 1.040342] Key type dns_resolver registered
[ 1.045519] registered taskstats version 1
[ 1.061463] uart-pl011 20201000.serial: cts_event_workaround enabled
[ 1.064877] 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2
[ 1.074440] console [ttyS0] disabled
[ 1.077666] 20215040.serial: ttyS0 at MMIO 0x0 (irq = 160, base_baud = 31250000) is a 16550
[ 2.000625] console [ttyS0] enabled
[ 2.009468] Indeed it is in host mode hprt0 = 00021501
[ 2.015005] mmc-bcm2835 20300000.mmc: mmc_debug:0 mmc_debug2:0
[ 2.015017] mmc-bcm2835 20300000.mmc: DMA channel allocated
[ 2.095076] sdhost: log_buf @ db513000 (5b513000)
[ 2.147334] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[ 2.157794] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 2.168450] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 2.180197] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[ 2.194660] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[ 2.205616] of_cfs_init
[ 2.210742] of_cfs_init: OK
[ 2.845696] irq 53: nobody cared (try booting with the "irqpoll" option)
[ 2.845716] CPU: 0 PID: 56 Comm: irq/53-bcm2835- Not tainted 4.14.31-rt25+ #1
[ 2.845721] Hardware name: BCM2835
[ 2.845791] [] (unwind_backtrace) from [] (show_stack+0x20/0x24)
[ 2.845818] [] (show_stack) from [] (dump_stack+0x20/0x28)
[ 2.845846] [] (dump_stack) from [] (__report_bad_irq+0x34/0x140)
[ 2.845866] [] (__report_bad_irq) from [] (note_interrupt+0x254/0x2b4)
[ 2.845885] [] (note_interrupt) from [] (handle_irq_event_percpu+0x78/0x90)
[ 2.845902] [] (handle_irq_event_percpu) from [] (handle_irq_event+0x5c/0xa0)
[ 2.845921] [] (handle_irq_event) from [] (handle_level_irq+0xb8/0x170)
[ 2.845939] [] (handle_level_irq) from [] (generic_handle_irq+0x30/0x44)
[ 2.845956] [] (generic_handle_irq) from [] (__handle_domain_irq+0x6c/0xe0)
[ 2.845974] [] (__handle_domain_irq) from [] (bcm2835_handle_irq+0x28/0x48)
[ 2.845992] [] (bcm2835_handle_irq) from [] (__irq_svc+0x5c/0xa8)
[ 2.846000] Exception stack(0xda527eb8 to 0xda527f00)
[ 2.846010] 7ea0: 00000000 00000001
[ 2.846025] 7ec0: 00400000 c097fc54 dac2a900 da4fb640 da526000 dac2a910 c0069e3c c0a0b712
[ 2.846039] 7ee0: dadb3c7c da527f24 da527f08 da527f08 c0069cf4 c0069cf8 40000113 ffffffff
[ 2.846057] [] (__irq_svc) from [] (irq_finalize_oneshot+0x8c/0x18c)
[ 2.846074] [] (irq_finalize_oneshot) from [] (irq_forced_thread_fn+0x40/0x64)
[ 2.846092] [] (irq_forced_thread_fn) from [] (irq_thread+0x108/0x1fc)
[ 2.846123] [] (irq_thread) from [] (kthread+0x124/0x160)
[ 2.846148] [] (kthread) from [] (ret_from_fork+0x14/0x20)
[ 2.846153] handlers:
[ 2.846164] [] irq_default_primary_handler threaded [] bcm2835_auxirq_handler
[ 2.846200] Disabling IRQ #53
[ 2.846503] usb 1-1: new high-speed USB device number 2 using dwc_otg
[ 2.856066] Waiting for root device PARTUUID=cb4a1ae3-02...
[ 2.948302] mmc1: new high speed SDIO card at address 0001
[ 3.016692] mmc0: host does not support reading read-only switch, assuming write-enable
[ 3.020314] mmc0: new high speed SDHC card at address aaaa
[ 3.024727] mmcblk0: mmc0:aaaa SB16G 14.8 GiB
[ 3.028198] mmcblk0: p1 p2
[ 3.057113] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 3.057229] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 3.061571] devtmpfs: mounted
[ 3.065824] Freeing unused kernel memory: 440K
[ 3.065833] This architecture does not have kernel memory protection.
[ 3.515351] Indeed it is in host mode hprt0 = 00001101
[ 3.626817] systemd[1]: System time before build time, advancing clock.
[ 3.793116] usb 1-1: New USB device found, idVendor=05ac, idProduct=1402
[ 3.803188] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3.805799] NET: Registered protocol family 10
[ 3.808267] Segment Routing with IPv6
[ 3.841261] usb 1-1: Product: Apple USB Ethernet Adapter
[ 3.843872] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 3.868350] usb 1-1: Manufacturer: Apple Inc.
[ 3.882214] usb 1-1: SerialNumber: 2421EF
[ 3.917751] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +
XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[ 3.946472] systemd[1]: Detected architecture arm.
[ 34.409263] systemd[1]: Set hostname to .
[ 65.765741] systemd[1]: Reached target Swap.
[ 95.845774] systemd[1]: Listening on udev Control Socket.
[ 125.925461] systemd[1]: Listening on fsck to fsckd communication Socket.
[ 156.006834] systemd[1]: Created slice User and Session Slice.
[ 186.085876] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ 216.196165] systemd[1]: Listening on Journal Socket (/dev/log).

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Apr 2, 2018

@jarodsmith This is another similar thing to #2424 since we can see "Disabling IRQ #53" here as well. @pelwell is working on this.

@paul-1

This comment has been minimized.

Copy link

paul-1 commented Jul 18, 2018

Just built 4.14.52-rt34, and it is now booting just fine on a RPi0 & RPi0W

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Jul 19, 2018

@paul-1 Sounds good :)

@FischC

This comment has been minimized.

Copy link

FischC commented Jul 26, 2018

I have "raspberrypi 4.14.52-rt34-v7+ #1 SMP PREEMPT RT" running stable with kernel parameters "dwc_otg.fiq_enable=0 dwc_otg.fiq_fsm_enable=0" or device tree overlay "dtoverlay=dwc2", but audio recordings from my USB sound card (C-Media Electronics, Inc.) are of poor quality (stuttering, noise, etc.).
Setting the CPU governor to "performance" and "/usr/bin/chrt -a -r -p 99" on the process (e.g. areocrd) improves the situation al little but sound quality is still poor/not acceptable.
I have no problem living with approx. 30% CPU overhead but I need good sound quality. Any suggestions?

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Jul 26, 2018

@FischC Did this happen with our previous -rt kernel? Anyway, I just update -rt to 4.14.58-rt34-v7.

pi@raspberrypi:~ $ uname -a
Linux raspberrypi 4.14.58-rt34-v7+ #25 SMP PREEMPT RT Thu Jul 26 17:55:41 CST 2018 armv7l GNU/Linux

@paul-1

This comment has been minimized.

Copy link

paul-1 commented Jul 26, 2018

Upgrade to the latest kernel, and then remove the fiq stuff from the command line. The latest kernel has patches to fix the fiq problems.

@soundchekk

This comment has been minimized.

Copy link

soundchekk commented Jul 26, 2018

Use a standard kernel if you don't really know what you're doing.
This is not the place to discuss application issues. Especially not "soundquality" related subjects.

Trying to use a rt-kernel properly on the Pi is trying to tune a 20 strings guitar by ear.

E.g. Using a USB DAC and network at the same time usually causes severe hickups if the entire
setup is not tuned properly. You might even never get it working properly. That gets much worse on higher samplerates (load).
By far the weakest spot of the PI the combined USB/networking chip and a single USB lane towards the CPU. That'll always cause major challenges.
Just lifting one priority to 99, basically locking up all the rest of the PI, is pretty much useless.

There's more. Not to be discussed over here I'd say. Except there'd be a real issue associated.

@FischC

This comment has been minimized.

Copy link

FischC commented Aug 23, 2018

@TiejunChina

I've updated to Linux raspberrypi 4.14.59-rt37-v7+ #4 SMP PREEMPT RT, removed the fiq stuff and now the kernel doesn't freeze that quickly.
But with high network traffic (iperf) on a USB Wifi adapter I can still force kernel freezes, etc.. I'm not sure how to address this issue then? Create a new ticket?

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Aug 27, 2018

@FischC Could you try the latest rpi-4.14.y-rt? If you still can reproduce that problem, please ping me again. But just sorry, I will probably not respond that timely because I will have a business travel this week.

@FischC

This comment has been minimized.

Copy link

FischC commented Sep 6, 2018

@TiejunChina I've tested with Linux "raspberrypi 4.14.66-rt40-v7+ #6 SMP PREEMPT RT Tue Aug 28 13:54:36 CEST 2018 armv7l GNU/Linux" and I can still reproduce the problem. Shall I create a new ticket?

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Sep 10, 2018

@FischC Please, go ahead.

@TiejunChina

This comment has been minimized.

Copy link
Collaborator

TiejunChina commented Sep 10, 2018

I'd like to close this issue since we have had our -rt branch for a while.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.