Skip to content

Screen flickers/works intermittently at default 1920x1080 resolution #27

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

Closed
joaodriessen opened this issue Apr 25, 2016 · 4 comments
Closed

Comments

@joaodriessen
Copy link

joaodriessen commented Apr 25, 2016

Hi Eric,

Amazed at the progress you're making.
I have an issue that the screen is black at the default 1920x1080 resolution. infrequently i get a picture for about a second and then it disappears again, setting the raspberry pi to output a resolution of 1280x720 does work.

by the way, probably a separate bug (and can file separately if you like) changing the screen resolution via /opt/vc/bin/tvservice causes a purple line(s) to appear at the screen edge(s).

I would like to post any relevant info you need to catch what's going on but I don't know what it is you need.

I'm running on a raspberry pi 3 with arch:
Linux alarmpi 4.4.8-1-ARCH #1 SMP Fri Apr 22 18:47:51 MDT 2016 armv7l GNU/Linux

config.txt:

hdmi_group=1

hdmi_mode=4

disable_overscan=1

framebuffer_depth=32

gpu_mem=256

dtoverlay=hifiberry-dacplus

dtoverlay=vc4-kms-v3d
avoid_warnings=2

The monitor i'm using works fine with other devices at 1920x1080 60/59mhz.

So grateful for your work, pretty soon I'll enjoy my raspberry pi almost as much as I do cookies.

@anholt
Copy link
Owner

anholt commented May 4, 2016

If you ask the firmware to change graphics settings at runtime, that will completely trash the open driver. You need to use the normal xrandr command, or whatever your desktop environment has as a friendly GUI, instead.

First step is attaching the dmesg, to make sure the clk driver isn't complaining about anything. We would probably want to compare /debug/clk/clk_summary to one on a working system at that resolution.

@joaodriessen
Copy link
Author

here's the output of dmesg:

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Initializing cgroup subsys cpuset
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Initializing cgroup subsys cpuacct
[ 0.000000] Linux version 4.4.9-1-ARCH (builduser@leming) (gcc version 5.3.0 (GCC) ) #1 SMP Fri May 6 12:52:32 MDT 2016
[ 0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] Machine model: Raspberry Pi 3 Model B Rev 1.2
[ 0.000000] cma: Reserved 256 MiB at 0x10000000
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] On node 0 totalpages: 241664
[ 0.000000] free_area_init_node: node 0, pgdat 80bf1200, node_mem_map ba72a000
[ 0.000000] Normal zone: 2124 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 241664 pages, LIFO batch:31
[ 0.000000] [bcm2709_smp_init_cpus] enter (9460->f3003010)
[ 0.000000] [bcm2709_smp_init_cpus] ncores=4
[ 0.000000] PERCPU: Embedded 13 pages/cpu @ba6e6000 s22604 r8192 d22452 u53248
[ 0.000000] pcpu-alloc: s22604 r8192 d22452 u53248 alloc=13*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 239540
[ 0.000000] Kernel command line: 8250.nr_uarts=1 cma=256M@256M dma.dmachans=0x7f35 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2709.boardrev=0xa02082 bcm2709.serial=0x7391aeb4 smsc95xx.macaddr=B8:27:EB:91:AE:B4 bcm2708_fb.fbswap=1 bcm2709.uart_clock=48000000 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000 root=/dev/mmcblk0p2 rw rootwait console=ttyS0,115200 console=tty1 selinux=0 plymouth.enable=0 smsc95xx.turbo_mode=N dwc_otg.lpm_enable=0 kgdboc=ttyS0,115200 elevator=noop quiet loglevel=3 vga=current
[ 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: 681320K/966656K available (8303K kernel code, 583K rwdata, 2924K rodata, 440K init, 797K bss, 23192K reserved, 262144K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
vmalloc : 0xbb800000 - 0xff800000 (1088 MB)
lowmem : 0x80000000 - 0xbb000000 ( 944 MB)
modules : 0x7f000000 - 0x80000000 ( 16 MB)
.text : 0x80008000 - 0x80aff22c (11229 kB)
.init : 0x80b00000 - 0x80b6e000 ( 440 kB)
.data : 0x80b6e000 - 0x80bfff98 ( 584 kB)
.bss : 0x80c02000 - 0x80cc95d0 ( 798 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, 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] Architected cp15 timer(s) running at 19.20MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[ 0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[ 0.000020] Switching to timer-based delay loop, resolution 52ns
[ 0.000245] Console: colour dummy device 80x30
[ 0.000411] console [tty1] enabled
[ 0.000446] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[ 0.000463] pid_max: default: 32768 minimum: 301
[ 0.000729] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000742] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.001570] Disabling cpuset control group subsystem
[ 0.001596] Initializing cgroup subsys io
[ 0.001622] Initializing cgroup subsys memory
[ 0.001654] Initializing cgroup subsys devices
[ 0.001669] Initializing cgroup subsys freezer
[ 0.001686] Initializing cgroup subsys net_cls
[ 0.001700] Initializing cgroup subsys perf_event
[ 0.001715] Initializing cgroup subsys net_prio
[ 0.001731] Initializing cgroup subsys pids
[ 0.001777] CPU: Testing write buffer coherency: ok
[ 0.002223] CPU0: update cpu_capacity 1024
[ 0.002234] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.002243] [bcm2709_smp_prepare_cpus] enter
[ 0.002351] Setting up static identity map for 0x8240 - 0x8274
[ 0.003850] [bcm2709_boot_secondary] cpu:1 started (0) 17
[ 0.004048] [bcm2709_secondary_init] enter cpu:1
[ 0.004086] CPU1: update cpu_capacity 1024
[ 0.004092] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.004464] [bcm2709_boot_secondary] cpu:2 started (0) 16
[ 0.004613] [bcm2709_secondary_init] enter cpu:2
[ 0.004633] CPU2: update cpu_capacity 1024
[ 0.004638] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.004972] [bcm2709_boot_secondary] cpu:3 started (0) 16
[ 0.005109] [bcm2709_secondary_init] enter cpu:3
[ 0.005128] CPU3: update cpu_capacity 1024
[ 0.005133] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.005188] Brought up 4 CPUs
[ 0.005209] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[ 0.005216] CPU: All CPU(s) started in HYP mode.
[ 0.005222] CPU: Virtualization extensions available.
[ 0.005834] devtmpfs: initialized
[ 0.014925] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[ 0.015235] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.023528] xor: measuring software checksum speed
[ 0.120010] arm4regs : 922.800 MB/sec
[ 0.220075] 8regs : 686.800 MB/sec
[ 0.320138] 32regs : 662.000 MB/sec
[ 0.420201] neon : 1107.200 MB/sec
[ 0.420210] xor: using function: neon (1107.200 MB/sec)
[ 0.420340] pinctrl core: initialized pinctrl subsystem
[ 0.420854] NET: Registered protocol family 16
[ 0.426184] DMA: preallocated 4096 KiB pool for atomic coherent allocations
[ 0.433538] bcm2709: Mini UART enabled
[ 0.433578] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[ 0.433586] hw-breakpoint: maximum watchpoint size is 8 bytes.
[ 0.433736] Serial: AMBA PL011 UART driver
[ 0.433874] uart-pl011 3f201000.uart: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[ 0.434031] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[ 0.670832] raid6: int32x1 gen() 101 MB/s
[ 0.840759] raid6: int32x1 xor() 74 MB/s
[ 1.010874] raid6: int32x2 gen() 151 MB/s
[ 1.180961] raid6: int32x2 xor() 97 MB/s
[ 1.351108] raid6: int32x4 gen() 163 MB/s
[ 1.521100] raid6: int32x4 xor() 114 MB/s
[ 1.691343] raid6: int32x8 gen() 166 MB/s
[ 1.861409] raid6: int32x8 xor() 113 MB/s
[ 2.031329] raid6: neonx1 gen() 353 MB/s
[ 2.201511] raid6: neonx1 xor() 315 MB/s
[ 2.371585] raid6: neonx2 gen() 537 MB/s
[ 2.541655] raid6: neonx2 xor() 461 MB/s
[ 2.711826] raid6: neonx4 gen() 648 MB/s
[ 2.881915] raid6: neonx4 xor() 497 MB/s
[ 3.052045] raid6: neonx8 gen() 641 MB/s
[ 3.222117] raid6: neonx8 xor() 474 MB/s
[ 3.222125] raid6: using algorithm neonx4 gen() 648 MB/s
[ 3.222132] raid6: .... xor() 497 MB/s, rmw enabled
[ 3.222139] raid6: using intx1 recovery algorithm
[ 3.222470] bcm2835-dma 3f007000.dma: DMA legacy API manager at f3007000, dmachans=0x1
[ 3.223899] SCSI subsystem initialized
[ 3.224177] usbcore: registered new interface driver usbfs
[ 3.224248] usbcore: registered new interface driver hub
[ 3.224354] usbcore: registered new device driver usb
[ 3.226573] raspberrypi-firmware soc:firmware: Attached to firmware from 2016-05-06 13:53
[ 3.254012] clocksource: Switched to clocksource arch_sys_counter
[ 3.309888] FS-Cache: Loaded
[ 3.310120] CacheFiles: Loaded
[ 3.320669] NET: Registered protocol family 2
[ 3.321392] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[ 3.321504] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[ 3.321691] TCP: Hash tables configured (established 8192 bind 8192)
[ 3.321782] UDP hash table entries: 512 (order: 2, 16384 bytes)
[ 3.321827] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[ 3.322039] NET: Registered protocol family 1
[ 3.322316] RPC: Registered named UNIX socket transport module.
[ 3.322325] RPC: Registered udp transport module.
[ 3.322332] RPC: Registered tcp transport module.
[ 3.322340] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 3.323521] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[ 3.326049] futex hash table entries: 1024 (order: 4, 65536 bytes)
[ 3.338478] VFS: Disk quotas dquot_6.6.0
[ 3.338736] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 3.341101] FS-Cache: Netfs 'nfs' registered for caching
[ 3.341838] NFS: Registering the id_resolver key type
[ 3.341877] Key type id_resolver registered
[ 3.341886] Key type id_legacy registered
[ 3.341911] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 3.342635] JFS: nTxBlock = 7370, nTxLock = 58966
[ 3.348502] SGI XFS with ACLs, security attributes, realtime, no debug enabled
[ 3.352230] aufs 4.4-20160328
[ 3.356613] async_tx: api initialized (async)
[ 3.356887] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[ 3.357011] io scheduler noop registered (default)
[ 3.357026] io scheduler deadline registered
[ 3.357073] io scheduler cfq registered
[ 3.357123] io scheduler bfq registered
[ 3.357130] BFQ I/O-scheduler: v7r11
[ 3.358892] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[ 3.359769] console [ttyS0] disabled
[ 3.359822] 3f215040.uart: ttyS0 at MMIO 0x3f215040 (irq = 59, base_baud = 50000000) is a 16550
[ 3.360395] console [ttyS0] enabled
[ 3.360816] KGDB: Registered I/O driver kgdboc
[ 3.394382] vc-cma: Videocore CMA driver
[ 3.394391] vc-cma: vc_cma_base = 0x00000000
[ 3.394399] vc-cma: vc_cma_size = 0x00000000 (0 MiB)
[ 3.394407] vc-cma: vc_cma_initial = 0x00000000 (0 MiB)
[ 3.394583] vc-mem: phys_addr:0x00000000 mem_base=0x3dc00000 mem_size:0x3f000000(1008 MiB)
[ 3.408090] brd: module loaded
[ 3.415997] loop: module loaded
[ 3.417447] vchiq: vchiq_init_state: slot_zero = 0x90400000, is_master = 0
[ 3.418775] Loading iSCSI transport class v2.0-870.
[ 3.419394] usbcore: registered new interface driver ax88179_178a
[ 3.419491] usbcore: registered new interface driver smsc95xx
[ 3.419603] usbcore: registered new interface driver cdc_ncm
[ 3.419620] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 3.619829] Core Release: 2.80a
[ 3.619840] Setting default values for core params
[ 3.619866] Finished setting default values for core params
[ 3.820162] Using Buffer DMA mode
[ 3.820171] Periodic Transfer Interrupt Enhancement - disabled
[ 3.820178] Multiprocessor Interrupt Enhancement - disabled
[ 3.820186] OTG VER PARAM: 0, OTG VER FLAG: 0
[ 3.820198] Dedicated Tx FIFOs mode
[ 3.820461] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0x90448000 dma = 0xd0448000 len=9024
[ 3.820490] FIQ FSM acceleration enabled for :
Non-periodic Split Transactions
Periodic Split Transactions
High-Speed Isochronous Endpoints
Interrupt/Control Split Transaction hack enabled
[ 3.820510] dwc_otg: Microframe scheduler enabled
[ 3.820554] WARN::hcd_init_fiq:413: FIQ on core 1 at 0x80617c84
[ 3.820567] WARN::hcd_init_fiq:414: FIQ ASM at 0x80617fcc length 36
[ 3.820580] WARN::hcd_init_fiq:439: MPHI regs_base at 0xbbcea000
[ 3.820632] dwc_otg 3f980000.usb: DWC OTG Controller
[ 3.820675] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[ 3.820707] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[ 3.820754] Init: Port Power? op_state=1
[ 3.820760] Init: Power Port (0)
[ 3.820938] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 3.820951] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 3.820962] usb usb1: Product: DWC OTG Controller
[ 3.820974] usb usb1: Manufacturer: Linux 4.4.9-1-ARCH dwc_otg_hcd
[ 3.820984] usb usb1: SerialNumber: 3f980000.usb
[ 3.821661] hub 1-0:1.0: USB hub found
[ 3.821699] hub 1-0:1.0: 1 port detected
[ 3.822227] dwc_otg: FIQ enabled
[ 3.822235] dwc_otg: NAK holdoff enabled
[ 3.822241] dwc_otg: FIQ split-transaction FSM enabled
[ 3.822271] Module dwc_common_port init
[ 3.822481] usbcore: registered new interface driver usb-storage
[ 3.822544] usbcore: registered new interface driver ums-alauda
[ 3.822601] usbcore: registered new interface driver ums-cypress
[ 3.822657] usbcore: registered new interface driver ums-datafab
[ 3.822713] usbcore: registered new interface driver ums_eneub6250
[ 3.822769] usbcore: registered new interface driver ums-freecom
[ 3.822832] usbcore: registered new interface driver ums-isd200
[ 3.822889] usbcore: registered new interface driver ums-jumpshot
[ 3.822945] usbcore: registered new interface driver ums-karma
[ 3.823002] usbcore: registered new interface driver ums-onetouch
[ 3.823081] usbcore: registered new interface driver ums-realtek
[ 3.823138] usbcore: registered new interface driver ums-sddr09
[ 3.823196] usbcore: registered new interface driver ums-sddr55
[ 3.823252] usbcore: registered new interface driver ums-usbat
[ 3.823483] mousedev: PS/2 mouse device common for all mice
[ 3.824167] md: linear personality registered for level -1
[ 3.824183] md: raid0 personality registered for level 0
[ 3.824196] md: raid1 personality registered for level 1
[ 3.824209] md: raid10 personality registered for level 10
[ 3.824434] md: raid6 personality registered for level 6
[ 3.824443] md: raid5 personality registered for level 5
[ 3.824451] md: raid4 personality registered for level 4
[ 3.824466] md: multipath personality registered for level -4
[ 3.824480] md: faulty personality registered for level -5
[ 3.824787] device-mapper: uevent: version 1.0.3
[ 3.825223] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: [email protected]
[ 3.825765] device-mapper: multipath: version 1.10.0 loaded
[ 3.825783] device-mapper: multipath round-robin: version 1.0.0 loaded
[ 3.825797] device-mapper: multipath queue-length: version 0.1.0 loaded
[ 3.825811] device-mapper: multipath service-time: version 0.2.0 loaded
[ 3.825841] device-mapper: raid: Loading target version 1.7.0
[ 3.826002] bcm2835-cpufreq: min=600000 max=1200000
[ 3.827726] sdhci: Secure Digital Host Controller Interface driver
[ 3.827730] sdhci: Copyright(c) Pierre Ossman
[ 3.827893] sdhost: log_buf @ 90446000 (d0446000)
[ 3.904017] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[ 3.906036] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[ 3.906042] mmc-bcm2835 3f300000.mmc: DMA channel allocated
[ 3.944052] sdhci-pltfm: SDHCI platform and OF driver helper
[ 3.944252] ledtrig-cpu: registered to indicate activity on CPUs
[ 3.944321] hidraw: raw HID events driver (C) Jiri Kosina
[ 3.944508] usbcore: registered new interface driver usbhid
[ 3.944512] usbhid: USB HID core driver
[ 3.945410] Initializing XFRM netlink socket
[ 3.945425] NET: Registered protocol family 17
[ 3.945492] Key type dns_resolver registered
[ 3.945840] Registering SWP/SWPB emulation handler
[ 3.946185] registered taskstats version 1
[ 3.947873] Btrfs loaded
[ 3.948417] Key type encrypted registered
[ 3.948457] vc-sm: Videocore shared memory driver
[ 3.948463] [vc_sm_connected_init]: start
[ 3.960707] mmc0: host does not support reading read-only switch, assuming write-enable
[ 3.962476] mmc0: new high speed SDXC card at address 0001
[ 3.962779] mmcblk0: mmc0:0001 00000 58.6 GiB
[ 3.963647] mmcblk0: p1 p2
[ 3.982522] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[ 3.984029] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 3.985519] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 3.988183] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[ 4.014059] Indeed it is in host mode hprt0 = 00021501
[ 4.036960] [vc_sm_connected_init]: end - returning 0
[ 4.038212] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
[ 4.038554] of_cfs_init
[ 4.038624] of_cfs_init: OK
[ 4.041482] md: Waiting for all devices to be available before autodetect
[ 4.041492] md: If you don't use raid, use raid=noautodetect
[ 4.042530] md: Autodetecting RAID arrays.
[ 4.042541] md: Scanned 0 and added 0 devices.
[ 4.042547] md: autorun ...
[ 4.042553] md: ... autorun DONE.
[ 4.045052] EXT4-fs (mmcblk0p2): couldn't mount as ext3 due to feature incompatibilities
[ 4.045654] EXT4-fs (mmcblk0p2): couldn't mount as ext2 due to feature incompatibilities
[ 4.065891] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 4.065931] VFS: Mounted root (ext4 filesystem) on device 179:2.
[ 4.067860] devtmpfs: mounted
[ 4.068533] Freeing unused kernel memory: 440K (80b00000 - 80b6e000)
[ 4.075226] mmc1: new high speed SDIO card at address 0001
[ 4.194050] usb 1-1: new high-speed USB device number 2 using dwc_otg
[ 4.194172] Indeed it is in host mode hprt0 = 00001101
[ 4.341748] systemd[1]: System time before build time, advancing clock.
[ 4.394316] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[ 4.394334] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 4.395136] hub 1-1:1.0: USB hub found
[ 4.395238] hub 1-1:1.0: 5 ports detected
[ 4.431061] NET: Registered protocol family 10
[ 4.445157] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 4.450224] random: systemd urandom read with 50 bits of entropy available
[ 4.471220] systemd[1]: systemd 229 running in system mode. (+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[ 4.471756] systemd[1]: Detected architecture arm.
[ 4.472663] systemd[1]: Set hostname to .
[ 4.674064] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[ 4.774322] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[ 4.774342] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 4.777056] smsc95xx v1.0.4
[ 4.837239] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:91:ae:b4
[ 5.007570] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[ 5.008057] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[ 5.008273] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ 5.008360] systemd[1]: Reached target Paths.
[ 5.008617] systemd[1]: Listening on Journal Socket.
[ 5.008730] systemd[1]: Reached target Encrypted Volumes.
[ 5.011274] systemd[1]: Set up automount media-Storage.automount.
[ 5.011864] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[ 5.027568] systemd[1]: Listening on Journal Socket (/dev/log).
[ 5.027763] systemd[1]: Listening on udev Kernel Socket.
[ 5.028132] systemd[1]: Listening on Network Service Netlink Socket.
[ 5.028224] systemd[1]: Reached target Remote File Systems.
[ 5.030431] systemd[1]: Created slice User and Session Slice.
[ 5.030654] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[ 5.030836] systemd[1]: Listening on LVM2 metadata daemon socket.
[ 5.031023] systemd[1]: Listening on udev Control Socket.
[ 5.031730] systemd[1]: Created slice System Slice.
[ 5.084047] usb 1-1.4: new low-speed USB device number 4 using dwc_otg
[ 5.094531] systemd[1]: Starting Set Up Additional Binary Formats...
[ 5.097841] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[ 5.099038] systemd[1]: Created slice system-getty.slice.
[ 5.117420] systemd[1]: Mounting Temporary Directory...
[ 5.130065] systemd[1]: Starting Load Kernel Modules...
[ 5.133587] systemd[1]: Mounting Debug File System...
[ 5.137503] systemd[1]: Starting Setup Virtual Console...
[ 5.141656] systemd[1]: Mounting POSIX Message Queue File System...
[ 5.151347] systemd[1]: Starting Remount Root and Kernel File Systems...
[ 5.151513] systemd[1]: Reached target Slices.
[ 5.155222] systemd[1]: Starting Journal Service...
[ 5.165900] systemd[1]: Listening on Process Core Dump Socket.
[ 5.167029] systemd[1]: Created slice system-serial\x2dgetty.slice.
[ 5.176535] systemd[1]: Started Create list of required static device nodes for the current kernel.
[ 5.177239] systemd[1]: systemd-modules-load.service: Main process exited, code=exited, status=1/FAILURE
[ 5.178856] systemd[1]: Failed to start Load Kernel Modules.
[ 5.179285] systemd[1]: systemd-modules-load.service: Unit entered failed state.
[ 5.179332] systemd[1]: systemd-modules-load.service: Failed with result 'exit-code'.
[ 5.180890] systemd[1]: Started Remount Root and Kernel File Systems.
[ 5.212554] systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 162 (systemd-binfmt)
[ 5.218257] systemd[1]: Mounted Debug File System.
[ 5.218702] systemd[1]: Mounted Temporary Directory.
[ 5.221466] systemd[1]: Mounted POSIX Message Queue File System.
[ 5.259073] usb 1-1.4: New USB device found, idVendor=04d9, idProduct=a06b
[ 5.259094] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 5.259106] usb 1-1.4: Product: Wireless USB Device
[ 5.259117] usb 1-1.4: Manufacturer: HOLTEK
[ 5.287076] input: HOLTEK Wireless USB Device as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.0/0003:04D9:A06B.0001/input/input0
[ 5.344867] hid-generic 0003:04D9:A06B.0001: input,hidraw0: USB HID v1.10 Keyboard [HOLTEK Wireless USB Device] on usb-3f980000.usb-1.4/input0
[ 5.412586] input: HOLTEK Wireless USB Device as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.1/0003:04D9:A06B.0002/input/input1
[ 5.464871] hid-generic 0003:04D9:A06B.0002: input,hiddev0,hidraw1: USB HID v1.10 Mouse [HOLTEK Wireless USB Device] on usb-3f980000.usb-1.4/input1
[ 5.574259] systemd[1]: Mounting Arbitrary Executable File Formats File System...
[ 5.576329] systemd[1]: Starting Load/Save Random Seed...
[ 5.594375] systemd[1]: Starting udev Coldplug all Devices...
[ 5.596695] systemd[1]: Mounting Configuration File System...
[ 5.599275] systemd[1]: Starting Apply Kernel Variables...
[ 5.601931] systemd[1]: Starting Create Static Device Nodes in /dev...
[ 5.604808] systemd[1]: Started Setup Virtual Console.
[ 5.623132] systemd[1]: Mounted Arbitrary Executable File Formats File System.
[ 5.623466] systemd[1]: Mounted Configuration File System.
[ 5.643554] systemd[1]: Started Load/Save Random Seed.
[ 5.662019] systemd[1]: Started Set Up Additional Binary Formats.
[ 5.704051] usb 1-1.2: new high-speed USB device number 5 using dwc_otg
[ 5.755396] systemd[1]: Started Apply Kernel Variables.
[ 5.825581] systemd[1]: Started udev Coldplug all Devices.
[ 5.943718] systemd[1]: Started Create Static Device Nodes in /dev.
[ 6.004478] systemd[1]: Starting udev Kernel Device Manager...
[ 6.004670] systemd[1]: Reached target Local File Systems (Pre).
[ 6.154028] usb 1-1.2: new high-speed USB device number 6 using dwc_otg
[ 6.254709] usb 1-1.2: New USB device found, idVendor=1058, idProduct=10a8
[ 6.254731] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 6.254743] usb 1-1.2: Product: Elements 10A8
[ 6.254754] usb 1-1.2: Manufacturer: Western Digital
[ 6.254765] usb 1-1.2: SerialNumber: 57584B31453633445058444A
[ 6.255631] usb-storage 1-1.2:1.0: USB Mass Storage device detected
[ 6.264206] scsi host0: usb-storage 1-1.2:1.0
[ 6.394369] systemd[1]: Started udev Kernel Device Manager.
[ 6.602256] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
[ 6.685666] systemd[1]: Started Journal Service.
[ 6.727649] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
[ 6.728044] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[ 7.105443] [drm] Initialized drm 1.1.0 20060810
[ 7.209918] systemd-journald[184]: Received request to flush runtime journal from PID 1
[ 7.511119] bcm2835-rng 3f104000.rng: hwrng registered
[ 7.511485] bcm2708_i2c 3f805000.i2c: BSC2 Controller at 0x3f805000 (irq 83) (baudrate 100000)
[ 7.878681] scsi 0:0:0:0: Direct-Access WD Elements 10A8 1042 PQ: 0 ANSI: 6
[ 7.879522] sd 0:0:0:0: [sda] 1953458176 512-byte logical blocks: (1.00 TB/931 GiB)
[ 7.879721] sd 0:0:0:0: [sda] Write Protect is off
[ 7.879729] sd 0:0:0:0: [sda] Mode Sense: 53 00 10 08
[ 7.879914] sd 0:0:0:0: [sda] No Caching mode page found
[ 7.879922] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 7.886136] random: nonblocking pool is initialized
[ 7.929655] sda: sda1 sda2 sda3
[ 7.930902] sd 0:0:0:0: [sda] Attached SCSI disk
[ 8.049502] vc4-drm soc:gpu@7e4c0000: bound 3f902000.hdmi (ops vc4_hdmi_ops [vc4])
[ 8.049673] vc4-drm soc:gpu@7e4c0000: bound 3f807000.pixelvalve (ops vc4_crtc_ops [vc4])
[ 8.049800] vc4-drm soc:gpu@7e4c0000: bound 3f207000.pixelvalve (ops vc4_crtc_ops [vc4])
[ 8.049923] vc4-drm soc:gpu@7e4c0000: bound 3f206000.pixelvalve (ops vc4_crtc_ops [vc4])
[ 8.049996] vc4-drm soc:gpu@7e4c0000: bound 3f400000.hvs (ops vc4_hvs_ops [vc4])
[ 8.050289] vc4-drm soc:gpu@7e4c0000: bound 3fc00000.v3d (ops vc4_v3d_ops [vc4])
[ 8.061153] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[ 8.061172] [drm] No driver support for vblank timestamp query.
[ 8.068101] brcmfmac: brcmf_sdio_drivestrengthinit: No SDIO Drive strength init done for chip 43430 rev 1 pmurev 24
[ 8.068751] usbcore: registered new interface driver brcmfmac
[ 8.118470] Console: switching to colour frame buffer device 240x67
[ 8.138106] cfg80211: World regulatory domain updated:
[ 8.138118] cfg80211: DFS Master region: unset
[ 8.138119] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[ 8.138129] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 8.138136] cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 8.138142] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[ 8.138151] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[ 8.138159] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[ 8.138166] cfg80211: (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[ 8.138172] cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[ 8.138178] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[ 8.166959] vc4-drm soc:gpu@7e4c0000: fb0: frame buffer device
[ 8.167954] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Dec 15 2015 18:10:45 version 7.45.41.23 (r606571) FWID 01-cc4eda9c
[ 8.190323] cfg80211: Updating information on frequency 2412 MHz with regulatory rule:
[ 8.190346] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190358] cfg80211: Updating information on frequency 2417 MHz with regulatory rule:
[ 8.190368] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190378] cfg80211: Updating information on frequency 2422 MHz with regulatory rule:
[ 8.190388] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190397] cfg80211: Updating information on frequency 2427 MHz with regulatory rule:
[ 8.190407] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190419] cfg80211: Updating information on frequency 2432 MHz with regulatory rule:
[ 8.190429] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190438] cfg80211: Updating information on frequency 2437 MHz with regulatory rule:
[ 8.190448] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190458] cfg80211: Updating information on frequency 2442 MHz with regulatory rule:
[ 8.190467] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190478] cfg80211: Updating information on frequency 2447 MHz with regulatory rule:
[ 8.190488] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190497] cfg80211: Updating information on frequency 2452 MHz with regulatory rule:
[ 8.190507] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190517] cfg80211: Updating information on frequency 2457 MHz with regulatory rule:
[ 8.190527] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190536] cfg80211: Updating information on frequency 2462 MHz with regulatory rule:
[ 8.190546] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190556] cfg80211: Updating information on frequency 2467 MHz with regulatory rule:
[ 8.190565] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190575] cfg80211: Updating information on frequency 2472 MHz with regulatory rule:
[ 8.190584] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (600 mBi, 2000 mBm)
[ 8.190594] cfg80211: Updating information on frequency 2484 MHz with regulatory rule:
[ 8.190605] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (600 mBi, 2000 mBm)
[ 8.190828] cfg80211: Ignoring regulatory request set by core since the driver uses its own custom regulatory domain
[ 8.190844] brcmfmac: brcmf_cfg80211_reg_notifier: not a ISO3166 code
[ 8.276656] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[ 8.771626] Adding 1048572k swap on /dev/sda2. Priority:-1 extents:1 across:1048572k FS
[ 8.846750] uart-pl011 3f201000.uart: no DMA platform data
[ 9.416153] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[ 9.416561] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 10.443237] Bluetooth: Core ver 2.21
[ 10.443294] NET: Registered protocol family 31
[ 10.443299] Bluetooth: HCI device and connection manager initialized
[ 10.443314] Bluetooth: HCI socket layer initialized
[ 10.443325] Bluetooth: L2CAP socket layer initialized
[ 10.443344] Bluetooth: SCO socket layer initialized
[ 10.478112] Bluetooth: HCI UART driver ver 2.3
[ 10.478127] Bluetooth: HCI UART protocol H4 registered
[ 10.478131] Bluetooth: HCI UART protocol BCSP registered
[ 10.478135] Bluetooth: HCI UART protocol LL registered
[ 10.478140] Bluetooth: HCI UART protocol ATH3K registered
[ 10.478144] Bluetooth: HCI UART protocol Three-wire (H5) registered
[ 10.478266] Bluetooth: HCI UART protocol BCM registered
[ 10.901738] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 10.901749] Bluetooth: BNEP filters: protocol multicast
[ 10.901767] Bluetooth: BNEP socket layer initialized
[ 10.931093] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 10.931934] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC1E1
[ 11.597898] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 11.638216] brcmfmac: brcmf_add_if: ERROR: netdev:wlan0 already exists
[ 11.638255] brcmfmac: brcmf_add_if: ignore IF event
[ 11.641927] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 11.641956] brcmfmac: power management disabled
[ 12.644915] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
[ 12.726735] brcmfmac: brcmf_add_if: ERROR: netdev:wlan0 already exists
[ 12.726737] brcmfmac: brcmf_add_if: ignore IF event
[ 12.760981] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 13.124032] ------------[ cut here ]------------
[ 13.124212] WARNING: CPU: 0 PID: 0 at drivers/gpu/drm/drm_irq.c:287 drm_update_vblank_count+0x164/0x318 drm
[ 13.124218] Modules linked in: bnep hci_uart btbcm bluetooth brcmfmac vc4 brcmutil drm_kms_helper cfg80211 drm syscopyarea sysfillrect sysimgblt fb_sys_fops bcm2835_rng i2c_bcm2708 rng_core bcm2835_gpiomem bcm2835_wdt evdev uio_pdrv_genirq uio sch_fq_codel binfmt_misc ip_tables x_tables ipv6
[ 13.124273] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.4.9-1-ARCH #1
[ 13.124277] Hardware name: BCM2709
[ 13.124298] <80015e9c> from <80012d78>
[ 13.124310] <80012d78> from <804f70a4>
[ 13.124321] <804f70a4> from <8002e7b8>
[ 13.124331] <8002e7b8> from <8002e884>
[ 13.124453] <8002e884> from [<7f0d92e8>](drm_update_vblank_count+0x164/0x318 [drm])
[ 13.124680] [<7f0d92e8>](drm_update_vblank_count [drm]) from [<7f0d9500>](vblank_disable_and_save+0x64/0x74 [drm])
[ 13.124897] [<7f0d9500>](vblank_disable_and_save [drm]) from [<7f0d9574>](vblank_disable_fn+0x64/0x90 [drm])
[ 13.125011] [<7f0d9574>](vblank_disable_fn [drm]) from <8008b168>
[ 13.125021] <8008b168> from <8008b4c0>
[ 13.125030] <8008b4c0> from <80032694>
[ 13.125039] <80032694> from <80032b3c>
[ 13.125047] <80032b3c> from <8007bc7c>
[ 13.125058] <8007bc7c> from <807ec080>
[ 13.125069] <807ec080> from <8000fdec>
[ 13.125080] <8000fdec> from <8006e00c>
[ 13.125091] <8006e00c> from <80b00ca4>
[ 13.125097] ---[ end trace 172ddbe03d05adfc ]---
[ 18.829263] fuse init (API version 7.23)
[ 19.002880] Bluetooth: RFCOMM TTY layer initialized
[ 19.002906] Bluetooth: RFCOMM socket layer initialized
[ 19.002926] Bluetooth: RFCOMM ver 1.11
[ 29.304873] EXT4-fs (sda3): mounted filesystem with ordered data mode. Opts: (null)
[ 68.314578] cfg80211: Verifying active interfaces after reg change

and here's my clk_summary:

clk_summary.txt

@anholt
Copy link
Owner

anholt commented May 11, 2016

    pllc                                  1            1  2390399926          0 0  
       pllc_per                           1            1  1195199963          0 0  
          hsm                             1            1   163620957          0 0  

I think this is it. The HDMI's been sourced from PLLC, which gets reclocked by the firmware. I think with https://lkml.org/lkml/2016/4/26/852 (which I should be sending off to rpi-4.4.y soon) you'll get stable video.

@joaodriessen
Copy link
Author

Just noticed the pull request, fantastic!

anholt pushed a commit that referenced this issue Feb 2, 2017
commit df49289 upstream.

Split irqchip allows pic and ioapic routes to be used without them being
created, which results in NULL access.  Check for NULL and avoid it.
(The setup is too racy for a nicer solutions.)

Found by syzkaller:

  general protection fault: 0000 [#1] SMP DEBUG_PAGEALLOC KASAN
  Dumping ftrace buffer:
     (ftrace buffer empty)
  Modules linked in:
  CPU: 3 PID: 11923 Comm: kworker/3:2 Not tainted 4.9.0-rc5+ #27
  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
  Workqueue: events irqfd_inject
  task: ffff88006a06c7c0 task.stack: ffff880068638000
  RIP: 0010:[...]  [...] __lock_acquire+0xb35/0x3380 kernel/locking/lockdep.c:3221
  RSP: 0000:ffff88006863ea20  EFLAGS: 00010006
  RAX: dffffc0000000000 RBX: dffffc0000000000 RCX: 0000000000000000
  RDX: 0000000000000039 RSI: 0000000000000000 RDI: 1ffff1000d0c7d9e
  RBP: ffff88006863ef58 R08: 0000000000000001 R09: 0000000000000000
  R10: 00000000000001c8 R11: 0000000000000000 R12: ffff88006a06c7c0
  R13: 0000000000000001 R14: ffffffff8baab1a0 R15: 0000000000000001
  FS:  0000000000000000(0000) GS:ffff88006d100000(0000) knlGS:0000000000000000
  CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
  CR2: 00000000004abdd0 CR3: 000000003e2f2000 CR4: 00000000000026e0
  Stack:
   ffffffff894d0098 1ffff1000d0c7d56 ffff88006863ecd0 dffffc0000000000
   ffff88006a06c7c0 0000000000000000 ffff88006863ecf8 0000000000000082
   0000000000000000 ffffffff815dd7c1 ffffffff00000000 ffffffff00000000
  Call Trace:
   [...] lock_acquire+0x2a2/0x790 kernel/locking/lockdep.c:3746
   [...] __raw_spin_lock include/linux/spinlock_api_smp.h:144
   [...] _raw_spin_lock+0x38/0x50 kernel/locking/spinlock.c:151
   [...] spin_lock include/linux/spinlock.h:302
   [...] kvm_ioapic_set_irq+0x4c/0x100 arch/x86/kvm/ioapic.c:379
   [...] kvm_set_ioapic_irq+0x8f/0xc0 arch/x86/kvm/irq_comm.c:52
   [...] kvm_set_irq+0x239/0x640 arch/x86/kvm/../../../virt/kvm/irqchip.c:101
   [...] irqfd_inject+0xb4/0x150 arch/x86/kvm/../../../virt/kvm/eventfd.c:60
   [...] process_one_work+0xb40/0x1ba0 kernel/workqueue.c:2096
   [...] worker_thread+0x214/0x18a0 kernel/workqueue.c:2230
   [...] kthread+0x328/0x3e0 kernel/kthread.c:209
   [...] ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:433

Reported-by: Dmitry Vyukov <[email protected]>
Fixes: 49df639 ("KVM: x86: Split the APIC from the rest of IRQCHIP.")
Signed-off-by: Radim Krčmář <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
anholt pushed a commit that referenced this issue Feb 28, 2017
Reviewed-by: Jeff Layton <[email protected]>
CC: Stable <[email protected]>

file_info_lock is not initalized in initiate_cifs_search(), leading to the
following splat after a simple "mount.cifs ... dir && ls dir/":

 BUG: spinlock bad magic on CPU#0, ls/486
  lock: 0xffff880009301110, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
 CPU: 0 PID: 486 Comm: ls Not tainted 4.9.0 #27
 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996)
  ffffc900042f3db0 ffffffff81327533 0000000000000000 ffff880009301110
  ffffc900042f3dd0 ffffffff810baf75 ffff880009301110 ffffffff817ae077
  ffffc900042f3df0 ffffffff810baff6 ffff880009301110 ffff880008d69900
 Call Trace:
  [<ffffffff81327533>] dump_stack+0x65/0x92
  [<ffffffff810baf75>] spin_dump+0x85/0xe0
  [<ffffffff810baff6>] spin_bug+0x26/0x30
  [<ffffffff810bb159>] do_raw_spin_lock+0xe9/0x130
  [<ffffffff8159ad2f>] _raw_spin_lock+0x1f/0x30
  [<ffffffff8127e50d>] cifs_closedir+0x4d/0x100
  [<ffffffff81181cfd>] __fput+0x5d/0x160
  [<ffffffff81181e3e>] ____fput+0xe/0x10
  [<ffffffff8109410e>] task_work_run+0x7e/0xa0
  [<ffffffff81002512>] exit_to_usermode_loop+0x92/0xa0
  [<ffffffff810026f9>] syscall_return_slowpath+0x49/0x50
  [<ffffffff8159b484>] entry_SYSCALL_64_fastpath+0xa7/0xa9

Fixes: 3afca26 ("Clarify locking of cifs file and tcon structures and make more granular")
Signed-off-by: Rabin Vincent <[email protected]>
Signed-off-by: Steve French <[email protected]>
anholt pushed a commit that referenced this issue Mar 2, 2017
commit 81ddd8c upstream.

Reviewed-by: Jeff Layton <[email protected]>

file_info_lock is not initalized in initiate_cifs_search(), leading to the
following splat after a simple "mount.cifs ... dir && ls dir/":

 BUG: spinlock bad magic on CPU#0, ls/486
  lock: 0xffff880009301110, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
 CPU: 0 PID: 486 Comm: ls Not tainted 4.9.0 #27
 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996)
  ffffc900042f3db0 ffffffff81327533 0000000000000000 ffff880009301110
  ffffc900042f3dd0 ffffffff810baf75 ffff880009301110 ffffffff817ae077
  ffffc900042f3df0 ffffffff810baff6 ffff880009301110 ffff880008d69900
 Call Trace:
  [<ffffffff81327533>] dump_stack+0x65/0x92
  [<ffffffff810baf75>] spin_dump+0x85/0xe0
  [<ffffffff810baff6>] spin_bug+0x26/0x30
  [<ffffffff810bb159>] do_raw_spin_lock+0xe9/0x130
  [<ffffffff8159ad2f>] _raw_spin_lock+0x1f/0x30
  [<ffffffff8127e50d>] cifs_closedir+0x4d/0x100
  [<ffffffff81181cfd>] __fput+0x5d/0x160
  [<ffffffff81181e3e>] ____fput+0xe/0x10
  [<ffffffff8109410e>] task_work_run+0x7e/0xa0
  [<ffffffff81002512>] exit_to_usermode_loop+0x92/0xa0
  [<ffffffff810026f9>] syscall_return_slowpath+0x49/0x50
  [<ffffffff8159b484>] entry_SYSCALL_64_fastpath+0xa7/0xa9

Fixes: 3afca26 ("Clarify locking of cifs file and tcon structures and make more granular")
Signed-off-by: Rabin Vincent <[email protected]>
Signed-off-by: Steve French <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
stschake pushed a commit to stschake/linux that referenced this issue Apr 11, 2018
Add a check for the length of the qpin structure to prevent out-of-bounds reads

BUG: KASAN: slab-out-of-bounds in create_raw_packet_qp+0x114c/0x15e2
Read of size 8192 at addr ffff880066b99290 by task syz-executor3/549

CPU: 3 PID: 549 Comm: syz-executor3 Not tainted 4.15.0-rc2+ anholt#27 Hardware
name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.7.5-0-ge51488c-20140602_164612-nilsson.home.kraxel.org 04/01/2014
Call Trace:
 dump_stack+0x8d/0xd4
 print_address_description+0x73/0x290
 kasan_report+0x25c/0x370
 ? create_raw_packet_qp+0x114c/0x15e2
 memcpy+0x1f/0x50
 create_raw_packet_qp+0x114c/0x15e2
 ? create_raw_packet_qp_tis.isra.28+0x13d/0x13d
 ? lock_acquire+0x370/0x370
 create_qp_common+0x2245/0x3b50
 ? destroy_qp_user.isra.47+0x100/0x100
 ? kasan_kmalloc+0x13d/0x170
 ? sched_clock_cpu+0x18/0x180
 ? fs_reclaim_acquire.part.15+0x5/0x30
 ? __lock_acquire+0xa11/0x1da0
 ? sched_clock_cpu+0x18/0x180
 ? kmem_cache_alloc_trace+0x17e/0x310
 ? mlx5_ib_create_qp+0x30e/0x17b0
 mlx5_ib_create_qp+0x33d/0x17b0
 ? sched_clock_cpu+0x18/0x180
 ? create_qp_common+0x3b50/0x3b50
 ? lock_acquire+0x370/0x370
 ? __radix_tree_lookup+0x180/0x220
 ? uverbs_try_lock_object+0x68/0xc0
 ? rdma_lookup_get_uobject+0x114/0x240
 create_qp.isra.5+0xce4/0x1e20
 ? ib_uverbs_ex_create_cq_cb+0xa0/0xa0
 ? copy_ah_attr_from_uverbs.isra.2+0xa00/0xa00
 ? ib_uverbs_cq_event_handler+0x160/0x160
 ? __might_fault+0x17c/0x1c0
 ib_uverbs_create_qp+0x21b/0x2a0
 ? ib_uverbs_destroy_cq+0x2e0/0x2e0
 ib_uverbs_write+0x55a/0xad0
 ? ib_uverbs_destroy_cq+0x2e0/0x2e0
 ? ib_uverbs_destroy_cq+0x2e0/0x2e0
 ? ib_uverbs_open+0x760/0x760
 ? futex_wake+0x147/0x410
 ? check_prev_add+0x1680/0x1680
 ? do_futex+0x3d3/0xa60
 ? sched_clock_cpu+0x18/0x180
 __vfs_write+0xf7/0x5c0
 ? ib_uverbs_open+0x760/0x760
 ? kernel_read+0x110/0x110
 ? lock_acquire+0x370/0x370
 ? __fget+0x264/0x3b0
 vfs_write+0x18a/0x460
 SyS_write+0xc7/0x1a0
 ? SyS_read+0x1a0/0x1a0
 ? trace_hardirqs_on_thunk+0x1a/0x1c
 entry_SYSCALL_64_fastpath+0x18/0x85
RIP: 0033:0x4477b9
RSP: 002b:00007f1822cadc18 EFLAGS: 00000292 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 00000000004477b9
RDX: 0000000000000070 RSI: 000000002000a000 RDI: 0000000000000005
RBP: 0000000000708000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000292 R12: 00000000ffffffff
R13: 0000000000005d70 R14: 00000000006e6e30 R15: 0000000020010ff0

Allocated by task 549:
 __kmalloc+0x15e/0x340
 kvmalloc_node+0xa1/0xd0
 create_user_qp.isra.46+0xd42/0x1610
 create_qp_common+0x2e63/0x3b50
 mlx5_ib_create_qp+0x33d/0x17b0
 create_qp.isra.5+0xce4/0x1e20
 ib_uverbs_create_qp+0x21b/0x2a0
 ib_uverbs_write+0x55a/0xad0
 __vfs_write+0xf7/0x5c0
 vfs_write+0x18a/0x460
 SyS_write+0xc7/0x1a0
 entry_SYSCALL_64_fastpath+0x18/0x85

Freed by task 368:
 kfree+0xeb/0x2f0
 kernfs_fop_release+0x140/0x180
 __fput+0x266/0x700
 task_work_run+0x104/0x180
 exit_to_usermode_loop+0xf7/0x110
 syscall_return_slowpath+0x298/0x370
 entry_SYSCALL_64_fastpath+0x83/0x85

The buggy address belongs to the object at ffff880066b99180  which
belongs to the cache kmalloc-512 of size 512 The buggy address is
located 272 bytes inside of  512-byte region [ffff880066b99180,
ffff880066b99380) The buggy address belongs to the page:
page:000000006040eedd count:1 mapcount:0 mapping:          (null)
index:0x0 compound_mapcount: 0
flags: 0x4000000000008100(slab|head)
raw: 4000000000008100 0000000000000000 0000000000000000 0000000180190019
raw: ffffea00019a7500 0000000b0000000b ffff88006c403080 0000000000000000
page dumped because: kasan: bad access detected

Memory state around the buggy address:
 ffff880066b99180: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 ffff880066b99200: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>ffff880066b99280: 00 00 fc fc fc fc fc fc fc fc fc fc fc fc fc fc
                         ^
 ffff880066b99300: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
 ffff880066b99380: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc

Cc: syzkaller <[email protected]>
Fixes: 0fb2ed6 ("IB/mlx5: Add create and destroy functionality for Raw Packet QP")
Signed-off-by: Boris Pismenny <[email protected]>
Signed-off-by: Leon Romanovsky <[email protected]>
Signed-off-by: Doug Ledford <[email protected]>
anholt pushed a commit that referenced this issue Apr 17, 2018
commit 2c292db upstream.

Add a check for the length of the qpin structure to prevent out-of-bounds reads

BUG: KASAN: slab-out-of-bounds in create_raw_packet_qp+0x114c/0x15e2
Read of size 8192 at addr ffff880066b99290 by task syz-executor3/549

CPU: 3 PID: 549 Comm: syz-executor3 Not tainted 4.15.0-rc2+ #27 Hardware
name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.7.5-0-ge51488c-20140602_164612-nilsson.home.kraxel.org 04/01/2014
Call Trace:
 dump_stack+0x8d/0xd4
 print_address_description+0x73/0x290
 kasan_report+0x25c/0x370
 ? create_raw_packet_qp+0x114c/0x15e2
 memcpy+0x1f/0x50
 create_raw_packet_qp+0x114c/0x15e2
 ? create_raw_packet_qp_tis.isra.28+0x13d/0x13d
 ? lock_acquire+0x370/0x370
 create_qp_common+0x2245/0x3b50
 ? destroy_qp_user.isra.47+0x100/0x100
 ? kasan_kmalloc+0x13d/0x170
 ? sched_clock_cpu+0x18/0x180
 ? fs_reclaim_acquire.part.15+0x5/0x30
 ? __lock_acquire+0xa11/0x1da0
 ? sched_clock_cpu+0x18/0x180
 ? kmem_cache_alloc_trace+0x17e/0x310
 ? mlx5_ib_create_qp+0x30e/0x17b0
 mlx5_ib_create_qp+0x33d/0x17b0
 ? sched_clock_cpu+0x18/0x180
 ? create_qp_common+0x3b50/0x3b50
 ? lock_acquire+0x370/0x370
 ? __radix_tree_lookup+0x180/0x220
 ? uverbs_try_lock_object+0x68/0xc0
 ? rdma_lookup_get_uobject+0x114/0x240
 create_qp.isra.5+0xce4/0x1e20
 ? ib_uverbs_ex_create_cq_cb+0xa0/0xa0
 ? copy_ah_attr_from_uverbs.isra.2+0xa00/0xa00
 ? ib_uverbs_cq_event_handler+0x160/0x160
 ? __might_fault+0x17c/0x1c0
 ib_uverbs_create_qp+0x21b/0x2a0
 ? ib_uverbs_destroy_cq+0x2e0/0x2e0
 ib_uverbs_write+0x55a/0xad0
 ? ib_uverbs_destroy_cq+0x2e0/0x2e0
 ? ib_uverbs_destroy_cq+0x2e0/0x2e0
 ? ib_uverbs_open+0x760/0x760
 ? futex_wake+0x147/0x410
 ? check_prev_add+0x1680/0x1680
 ? do_futex+0x3d3/0xa60
 ? sched_clock_cpu+0x18/0x180
 __vfs_write+0xf7/0x5c0
 ? ib_uverbs_open+0x760/0x760
 ? kernel_read+0x110/0x110
 ? lock_acquire+0x370/0x370
 ? __fget+0x264/0x3b0
 vfs_write+0x18a/0x460
 SyS_write+0xc7/0x1a0
 ? SyS_read+0x1a0/0x1a0
 ? trace_hardirqs_on_thunk+0x1a/0x1c
 entry_SYSCALL_64_fastpath+0x18/0x85
RIP: 0033:0x4477b9
RSP: 002b:00007f1822cadc18 EFLAGS: 00000292 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 00000000004477b9
RDX: 0000000000000070 RSI: 000000002000a000 RDI: 0000000000000005
RBP: 0000000000708000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000292 R12: 00000000ffffffff
R13: 0000000000005d70 R14: 00000000006e6e30 R15: 0000000020010ff0

Allocated by task 549:
 __kmalloc+0x15e/0x340
 kvmalloc_node+0xa1/0xd0
 create_user_qp.isra.46+0xd42/0x1610
 create_qp_common+0x2e63/0x3b50
 mlx5_ib_create_qp+0x33d/0x17b0
 create_qp.isra.5+0xce4/0x1e20
 ib_uverbs_create_qp+0x21b/0x2a0
 ib_uverbs_write+0x55a/0xad0
 __vfs_write+0xf7/0x5c0
 vfs_write+0x18a/0x460
 SyS_write+0xc7/0x1a0
 entry_SYSCALL_64_fastpath+0x18/0x85

Freed by task 368:
 kfree+0xeb/0x2f0
 kernfs_fop_release+0x140/0x180
 __fput+0x266/0x700
 task_work_run+0x104/0x180
 exit_to_usermode_loop+0xf7/0x110
 syscall_return_slowpath+0x298/0x370
 entry_SYSCALL_64_fastpath+0x83/0x85

The buggy address belongs to the object at ffff880066b99180  which
belongs to the cache kmalloc-512 of size 512 The buggy address is
located 272 bytes inside of  512-byte region [ffff880066b99180,
ffff880066b99380) The buggy address belongs to the page:
page:000000006040eedd count:1 mapcount:0 mapping:          (null)
index:0x0 compound_mapcount: 0
flags: 0x4000000000008100(slab|head)
raw: 4000000000008100 0000000000000000 0000000000000000 0000000180190019
raw: ffffea00019a7500 0000000b0000000b ffff88006c403080 0000000000000000
page dumped because: kasan: bad access detected

Memory state around the buggy address:
 ffff880066b99180: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 ffff880066b99200: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>ffff880066b99280: 00 00 fc fc fc fc fc fc fc fc fc fc fc fc fc fc
                         ^
 ffff880066b99300: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
 ffff880066b99380: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc

Cc: syzkaller <[email protected]>
Fixes: 0fb2ed6 ("IB/mlx5: Add create and destroy functionality for Raw Packet QP")
Signed-off-by: Boris Pismenny <[email protected]>
Signed-off-by: Leon Romanovsky <[email protected]>
Signed-off-by: Doug Ledford <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
anholt pushed a commit that referenced this issue Jun 29, 2018
…_neon_begin, _end

In a arm64 server(QDF2400),I met a similar might-sleep warning as [1]:
[    7.019116] BUG: sleeping function called from invalid context at
./include/crypto/algapi.h:416
[    7.027863] in_atomic(): 1, irqs_disabled(): 0, pid: 410, name:
cryptomgr_test
[    7.035106] 1 lock held by cryptomgr_test/410:
[    7.039549]  #0:         (ptrval) (&drbg->drbg_mutex){+.+.}, at:
drbg_instantiate+0x34/0x398
[    7.048038] CPU: 9 PID: 410 Comm: cryptomgr_test Not tainted
4.17.0-rc6+ #27
[    7.068228]  dump_backtrace+0x0/0x1c0
[    7.071890]  show_stack+0x24/0x30
[    7.075208]  dump_stack+0xb0/0xec
[    7.078523]  ___might_sleep+0x160/0x238
[    7.082360]  skcipher_walk_done+0x118/0x2c8
[    7.086545]  ctr_encrypt+0x98/0x130
[    7.090035]  simd_skcipher_encrypt+0x68/0xc0
[    7.094304]  drbg_kcapi_sym_ctr+0xd4/0x1f8
[    7.098400]  drbg_ctr_update+0x98/0x330
[    7.102236]  drbg_seed+0x1b8/0x2f0
[    7.105637]  drbg_instantiate+0x2ac/0x398
[    7.109646]  drbg_kcapi_seed+0xbc/0x188
[    7.113482]  crypto_rng_reset+0x4c/0xb0
[    7.117319]  alg_test_drbg+0xec/0x330
[    7.120981]  alg_test.part.6+0x1c8/0x3c8
[    7.124903]  alg_test+0x58/0xa0
[    7.128044]  cryptomgr_test+0x50/0x58
[    7.131708]  kthread+0x134/0x138
[    7.134936]  ret_from_fork+0x10/0x1c

Seems there is a bug in Ard Biesheuvel's commit.
Fixes: 6833817 ("crypto: arm64/aes-blk - move kernel mode neon
en/disable into loop")

[1] https://www.spinics.net/lists/linux-crypto/msg33103.html

Signed-off-by: [email protected]
Acked-by: Ard Biesheuvel <[email protected]>
Cc: <[email protected]> # 4.17
Acked-by: Will Deacon <[email protected]>
Signed-off-by: Herbert Xu <[email protected]>
anholt pushed a commit that referenced this issue Jun 29, 2018
lockdep spotted that we are using rfs_h.lock in enic_get_rxnfc() without
initializing. rfs_h.lock is initialized in enic_open(). But ethtool_ops
can be called when interface is down.

Move enic_rfs_flw_tbl_init to enic_probe.

INFO: trying to register non-static key.
the code is fine but needs lockdep annotation.
turning off the locking correctness validator.
CPU: 18 PID: 1189 Comm: ethtool Not tainted 4.17.0-rc7-devel+ #27
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.11.0-20171110_100015-anatol 04/01/2014
Call Trace:
dump_stack+0x85/0xc0
register_lock_class+0x550/0x560
? __handle_mm_fault+0xa8b/0x1100
__lock_acquire+0x81/0x670
lock_acquire+0xb9/0x1e0
?  enic_get_rxnfc+0x139/0x2b0 [enic]
_raw_spin_lock_bh+0x38/0x80
? enic_get_rxnfc+0x139/0x2b0 [enic]
enic_get_rxnfc+0x139/0x2b0 [enic]
ethtool_get_rxnfc+0x8d/0x1c0
dev_ethtool+0x16c8/0x2400
? __mutex_lock+0x64d/0xa00
? dev_load+0x6a/0x150
dev_ioctl+0x253/0x4b0
sock_do_ioctl+0x9a/0x130
sock_ioctl+0x1af/0x350
do_vfs_ioctl+0x8e/0x670
? syscall_trace_enter+0x1e2/0x380
ksys_ioctl+0x60/0x90
__x64_sys_ioctl+0x16/0x20
do_syscall_64+0x5a/0x170
entry_SYSCALL_64_after_hwframe+0x49/0xbe

Signed-off-by: Govindarajulu Varadarajan <[email protected]>
Signed-off-by: David S. Miller <[email protected]>
lategoodbye pushed a commit that referenced this issue May 25, 2019
In virtualized setup, when system reboots due to warm
reset interrupt storm is seen.

Call Trace:
<IRQ>
dump_stack+0x70/0xa5
__report_bad_irq+0x2e/0xc0
note_interrupt+0x248/0x290
? add_interrupt_randomness+0x30/0x220
handle_irq_event_percpu+0x54/0x80
handle_irq_event+0x39/0x60
handle_fasteoi_irq+0x91/0x150
handle_irq+0x108/0x180
do_IRQ+0x52/0xf0
common_interrupt+0xf/0xf
</IRQ>
RIP: 0033:0x76fc2cfabc1d
Code: 24 28 bf 03 00 00 00 31 c0 48 8d 35 63 77 0e 00 48 8d 15 2e
94 0e 00 4c 89 f9 49 89 d9 4c 89 d3 e8 b8 e2 01 00 48 8b 54 24 18
<48> 89 ef 48 89 de 4c 89 e1 e8 d5 97 01 00 84 c0 74 2d 48 8b 04
24
RSP: 002b:00007ffd247c1fc0 EFLAGS: 00000293 ORIG_RAX: ffffffffffffffda
RAX: 0000000000000000 RBX: 00007ffd247c1ff0 RCX: 000000000003d3ce
RDX: 0000000000000000 RSI: 00007ffd247c1ff0 RDI: 000076fc2cbb6010
RBP: 000076fc2cded010 R08: 00007ffd247c2210 R09: 00007ffd247c22a0
R10: 000076fc29465470 R11: 0000000000000000 R12: 00007ffd247c1fc0
R13: 000076fc2ce8e470 R14: 000076fc27ec9960 R15: 0000000000000414
handlers:
[<000000000d3fa913>] idma64_irq
Disabling IRQ #27

To avoid interrupt storm, set the device in reset state
before bringing out the device from reset state.

Changelog v2:
- correct the subject line by adding "mfd: "

Signed-off-by: Binbin Wu <[email protected]>
Acked-by: Mika Westerberg <[email protected]>
Reviewed-by: Andy Shevchenko <[email protected]>
Signed-off-by: Lee Jones <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants