4.7.2-grsec on RPi won't boot

[radegand]

Hi,

There seems to be a problem with the current grsec kernel on RPi (I haven't tried on any other ARM platform).

Vanilla 4.7.2 works fine, but enabling grsecurity prevents the kernel from booting. It will hang on the "Starting kernel..." message as can be seen below: (I've tried desktop+performance and server+security settings)

Code: Select all

U-Boot 2016.09-rc2-00002-g46fe9eb (Aug 28 2016 - 11:32:04 +0200)

DRAM:  128 MiB
RPI Model B (0x2)
MMC:   bcm2835_sdhci: 0
reading uboot.env

** Unable to read "uboot.env" from mmc0:1 **
Using default environment

In:    serial
Out:   lcd
Err:   lcd
Net:   Net Initialization Skipped
No ethernet found.
starting USB...
USB0:   Core Release: 2.80a
scanning bus 0 for devices... 3 USB Device(s) found
       scanning usb for storage devices... 0 Storage Device(s) found
       scanning usb for ethernet devices... 1 Ethernet Device(s) found
Hit any key to stop autoboot:  0
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Found U-Boot script /boot.scr.uimg
reading /boot.scr.uimg
321 bytes read in 12 ms (25.4 KiB/s)
## Executing script at 02000000
switch to partitions #0, OK
mmc0 is current device
reading zImage
3676320 bytes read in 263 ms (13.3 MiB/s)
reading bcm2835-rpi-b.dtb
6468 bytes read in 15 ms (420.9 KiB/s)
Kernel image @ 0x1000000 [ 0x000000 - 0x3818a0 ]
## Flattened Device Tree blob at 00000100
   Booting using the fdt blob at 0x000100
   Using Device Tree in place at 00000100, end 00004a43

Starting kernel ...


The last one I tried on RPI was 4.5.2-grsec which was working fine on RPi.

Is there a way to get more verbose information on what's going on at this stage? (like a kernel option to enable to get more verbose log?)

Help will be appreciated, thanks in advance!
Radek

[PaX Team]

since it's such an early problem i wonder if you can debug this in qemu perhaps?

[radegand]

since it's such an early problem i wonder if you can debug this in qemu perhaps?

I shall learn how it's done and report back should this yield any meaningful results...
Thanks for the hint!

Radek

[radegand]

Ok, so I've enabled some debugging options and managed to get this far, capture from serial console.

Please note that this is on RPI2 and not RPI, although it's seems like a similar problem, as they were both hanging at the 'starting the kernel' point.
Vanilla 4.7.4 on RPI2 boots fine.

I'll check if I get the same error on RPI, in the meantime,please see the log below:

Code: Select all

No ethernet found.
starting USB...
USB0:   Core Release: 2.80a
scanning bus 0 for devices... 3 USB Device(s) found
       scanning usb for storage devices... 0 Storage Device(s) found
       scanning usb for ethernet devices... 1 Ethernet Device(s) found
Hit any key to stop autoboot:  0
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Found U-Boot script /boot.scr.uimg
reading /boot.scr.uimg
323 bytes read in 9 ms (34.2 KiB/s)
## Executing script at 02000000
switch to partitions #0, OK
mmc0 is current device
reading zImage
3780968 bytes read in 493 ms (7.3 MiB/s)
reading bcm2836-rpi-2-b.dtb
7294 bytes read in 18 ms (395.5 KiB/s)
Kernel image @ 0x1000000 [ 0x000000 - 0x39b168 ]
## Flattened Device Tree blob at 00000100
   Booting using the fdt blob at 0x000100
   Using Device Tree in place at 00000100, end 00004d7d

Starting kernel ...

Uncompressing Linux... done, booting the kernel.
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.7.4-grsec (radek@laura-lap) (gcc version 5.4.0 20160609 (Ubuntu/Linaro 5.4.0-6ubuntu1~16.04.1) ) #2 Mon Sep 26 21:17:26 CEST 2016
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c53c7d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] Machine model: Raspberry Pi 2 Model B
[    0.000000] bootconsole [earlycon0] enabled
[    0.000000] Memory policy: Data cache writeback
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: CPU: 0 PID: 0 at arch/arm/kernel/devtree.c:149 arm_dt_init_cpu_maps+0x1d0/0x360
[    0.000000] DT /cpu 2 nodes greater than max cores 1, capping them
[    0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.7.4-grsec #2
[    0.000000] Hardware name: BCM2835
[    0.000000] [<c010e220>] (unwind_backtrace+0x0/0xdc) from [<c010c310>] (show_stack+0x10/0x14)
[    0.000000] [<c010c310>] (show_stack+0x10/0x14) from [<c011c308>] (__warn+0xc4/0xf4)
[    0.000000] [<c011c308>] (__warn+0xc4/0xf4) from [<c011c36c>] (warn_slowpath_fmt+0x34/0x44)
[    0.000000] [<c011c36c>] (warn_slowpath_fmt+0x34/0x44) from [<c0909494>] (arm_dt_init_cpu_maps+0x1d0/0x360)
[    0.000000] [<c0909494>] (arm_dt_init_cpu_maps+0x1d0/0x360) from [<c09084dc>] (setup_arch+0x128c/0x13a0)
[    0.000000] [<c09084dc>] (setup_arch+0x128c/0x13a0) from [<c09017f0>] (start_kernel+0x9c/0x670)
[    0.000000] [<c09017f0>] (start_kernel+0x9c/0x670) from [<00008078>] (0x8078)
[    0.000000] ---[ end trace 745b1d174ea25990 ]---
[    0.000000] DT missing boot CPU MPIDR[23:0], fall back to default cpu_logical_map
[    0.000000] CPU: All CPU(s) started in HYP mode.
[    0.000000] CPU: Virtualization extensions available.
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line: earlyprintk console=tty0 console=ttyAMA0 root=/dev/mmcblk0p2 rootwait
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Memory: 119720K/131072K available (6144K kernel code, 130K rwdata, 1720K rodata, 1024K init, 779K bss, 11352K reserved, 0K 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 : 0xc8800000 - 0xff800000   ( 880 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xc8000000   ( 128 MB)
[    0.000000]       .text : 0xc0008000 - 0xc0700000   (7136 kB)
[    0.000000]       .init : 0xc0900000 - 0xc0a00000   (1024 kB)
[    0.000000]       .data : 0xc0a00000 - 0xc0a20a60   ( 131 kB)
[    0.000000]        .bss : 0xc0a20a60 - 0xc0ae38ec   ( 780 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000024] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.008593] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.018167] bcm2835: system timer (irq = 33)
[    0.022893] Architected cp15 timer(s) running at 19.20MHz (phys).
[    0.029170] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.040198] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.048408] Switching to timer-based delay loop, resolution 52ns
[    0.054892] Console: colour dummy device 80x30
[    0.060652] console [tty0] enabled
[    0.064217] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.074856] pid_max: default: 32768 minimum: 501
[    0.079953] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.086794] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.095242] CPU: Testing write buffer coherency: ok
[    0.100822] Setting up static identity map for 0x100000 - 0x10004c
[    0.107221] PAX: swapper:1, uid/euid: 0/0, attempted to access userland memory at 6723b900
[    0.115744] Unable to handle kernel paging request at virtual address 6723b900
[    0.123193] pgd = c0004000
[    0.126046] [6723b900] *pgd=00000000
[    0.129792] Internal error: Oops: 2805 [#1] ARM
[    0.134499] CPU: 0 PID: 1 Comm: swapper Tainted: G        W       4.7.4-grsec #2
[    0.142116] Hardware name: BCM2835
[    0.145669] task: c7844000 ti: c7842000 task.ti: c7842000
[    0.151266] PC is at v7_flush_kern_dcache_area+0x20/0x38
[    0.156769] LR is at init_static_idmap+0x1dc/0x280
[    0.161733] pc : [<c01167f8>]    lr : [<c090b79c>]    psr: 60000053
[    0.161733] sp : c7843ed0  ip : 0010004b  fp : c7843f04
[    0.173583] r10: ffe00000  r9 : c0a0da28  r8 : 0010004c
[    0.178987] r7 : c47eea3a  r6 : b48abf94  r5 : c7850008  r4 : 00100402
[    0.185708] r3 : 0000003f  r2 : 00000040  r1 : 6723b900  r0 : 6723b900
[    0.192437] Flags: nZCv  IRQs on  FIQs off  Mode SVC_32  ISA ARM  Segment none
[    0.199878] Control: 10c53c7d  Table: 00004059  DAC: 00000011
[    0.205808] Process swapper (pid: 1, stack limit = 0xc7842208)
[    0.211829] Stack: (0xc7843ed0 to 0xc7844000)
[    0.216350] 3ec0:                                     8abf94c4 7eea3ab4 4d670694 95a75559
[    0.224768] 3ee0: c7843fa4 ffffe000 00000000 21dd3c3e 132cdb78 7f870bd3 364a207b c090b5c0
[    0.233186] 3f00: c7843f54 c0901edc c7843f38 c0329e4c c7843f38 c0957004 c7843f38 c0a0da28
[    0.241604] 3f20: 385e99b2 5103dbfc 00000000 00000001 c7844000 d79b0ae1 d880d918 5f51527e
[    0.250020] 3f40: e8357d1a c0a0da28 c096740c c0967424 c7843fa4 c0902184 00000000 00000000
[    0.258436] 3f60: 00000000 00000000 00000000 00000000 00000000 00000000 a4fdd06a fa34bea2
[    0.266852] 3f80: c060ebc8 00000000 c060ebc8 00000000 00000000 00000000 00000000 00000000
[    0.275266] 3fa0: 00000000 c060ebd0 00000000 c0107358 00000000 00000000 00000000 00000000
[    0.283685] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[    0.292097] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000
[    0.300539] [<c01167f8>] (v7_flush_kern_dcache_area+0x20/0x38) from [<c090b79c>] (init_static_idmap+0x1dc/0x280)
[    0.310995] [<c090b79c>] (init_static_idmap+0x1dc/0x280) from [<c0901edc>] (do_one_initcall+0x118/0x2d8)
[    0.320745] [<c0901edc>] (do_one_initcall+0x118/0x2d8) from [<c0902184>] (kernel_init_freeable+0xe8/0x3cc)
[    0.330666] [<c0902184>] (kernel_init_freeable+0xe8/0x3cc) from [<c060ebd0>] (kernel_init+0x8/0x118)
[    0.340066] [<c060ebd0>] (kernel_init+0x8/0x118) from [<c0107358>] (ret_from_fork+0x14/0x3c)
[    0.348753] Code: e1a02312 e0801001 e2423001 e1c00003 (ee070f3e)
[    0.355055] ---[ end trace 745b1d174ea25991 ]---
[    0.359842] Kernel panic - not syncing: grsec: halting the system due to suspicious kernel crash caused by root
[    0.370195] ---[ end Kernel panic - not syncing: grsec: halting the system due to suspicious kernel crash caused by root


[radegand]

...and a log from RPI below:

Code: Select all

Out:   lcd
Err:   lcd
Net:   Net Initialization Skipped
No ethernet found.
starting USB...
USB0:   Core Release: 2.80a
scanning bus 0 for devices... 3 USB Device(s) found
       scanning usb for storage devices... 0 Storage Device(s) found
       scanning usb for ethernet devices... 1 Ethernet Device(s) found
Hit any key to stop autoboot:  0
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Found U-Boot script /boot.scr.uimg
reading /boot.scr.uimg
321 bytes read in 10 ms (31.3 KiB/s)
## Executing script at 02000000
switch to partitions #0, OK
mmc0 is current device
reading zImage
3676320 bytes read in 263 ms (13.3 MiB/s)
reading bcm2835-rpi-b.dtb
6468 bytes read in 15 ms (420.9 KiB/s)
Kernel image @ 0x1000000 [ 0x000000 - 0x3818a0 ]
## Flattened Device Tree blob at 00000100
   Booting using the fdt blob at 0x000100
   Using Device Tree in place at 00000100, end 00004a43

Starting kernel ...



U-Boot 2016.09-rc2-00002-g46fe9eb (Aug 28 2016 - 11:32:04 +0200)

DRAM:  128 MiB
RPI Model B (0x2)
MMC:   bcm2835_sdhci: 0
reading uboot.env

** Unable to read "uboot.env" from mmc0:1 **
Using default environment

In:    serial
Out:   lcd
Err:   lcd
Net:   Net Initialization Skipped
No ethernet found.
starting USB...
USB0:   Core Release: 2.80a
scanning bus 0 for devices... 3 USB Device(s) found
       scanning usb for storage devices... 0 Storage Device(s) found
       scanning usb for ethernet devices... 1 Ethernet Device(s) found
Hit any key to stop autoboot:  0
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Found U-Boot script /boot.scr.uimg
reading /boot.scr.uimg
321 bytes read in 10 ms (31.3 KiB/s)
## Executing script at 02000000
switch to partitions #0, OK
mmc0 is current device
reading zImage
3778688 bytes read in 272 ms (13.2 MiB/s)
reading bcm2835-rpi-b.dtb
6468 bytes read in 14 ms (451.2 KiB/s)
Kernel image @ 0x1000000 [ 0x000000 - 0x39a880 ]
## Flattened Device Tree blob at 00000100
   Booting using the fdt blob at 0x000100
   Using Device Tree in place at 00000100, end 00004a43

Starting kernel ...

Uncompressing Linux... done, booting the kernel.
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.7.4-grsec (radek@laura-lap) (gcc version 5.4.0 20160609 (Ubuntu/Linaro 5.4.0-6ubuntu1~16.04.1) ) #1 Mon Sep 26 21:31:40 CEST 2016
[    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] Machine model: Raspberry Pi Model B
[    0.000000] bootconsole [earlycon0] enabled
[    0.000000] Memory policy: Data cache writeback
[    0.000000] CPU: All CPU(s) started in SVC mode.
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line: earlyprintk console=tty0 console=ttyAMA0 root=/dev/mmcblk0p2 rootwait
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Memory: 119724K/131072K available (6144K kernel code, 130K rwdata, 1720K rodata, 1024K init, 779K bss, 11348K reserved, 0K 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 : 0xc8800000 - 0xff800000   ( 880 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xc8000000   ( 128 MB)
[    0.000000]       .text : 0xc0008000 - 0xc0700000   (7136 kB)
[    0.000000]       .init : 0xc0900000 - 0xc0a00000   (1024 kB)
[    0.000000]       .data : 0xc0a00000 - 0xc0a20a60   ( 131 kB)
[    0.000000]        .bss : 0xc0a20a60 - 0xc0ae38ec   ( 780 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000026] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.008542] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.018056] bcm2835: system timer (irq = 27)
[    0.022853] Console: colour dummy device 80x30
[    0.028142] console [tty0] enabled
[    0.031698] Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792)
[    0.091033] pid_max: default: 32768 minimum: 501
[    0.096139] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.102983] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.111466] CPU: Testing write buffer coherency: ok
[    0.117083] Setting up static identity map for 0x100000 - 0x10004c
[    0.123459] Unable to handle kernel paging request at virtual address e3ed1a20
[    0.130870] pgd = c0004000
[    0.133703] [e3ed1a20] *pgd=00000000
[    0.137426] Internal error: Oops: 805 [#1] ARM
[    0.142021] CPU: 0 PID: 1 Comm: swapper Not tainted 4.7.4-grsec #1
[    0.148353] Hardware name: BCM2835
[    0.151892] task: c7844000 ti: c7842000 task.ti: c7842000
[    0.157457] PC is at v6_flush_kern_dcache_area+0x8/0x24
[    0.162853] LR is at init_static_idmap+0x1dc/0x280
[    0.167796] pc : [<c0116324>]    lr : [<c090b78c>]    psr: 60000053
[    0.167796] sp : c7843ed0  ip : 0010004b  fp : c7843f04
[    0.179576] r10: ffe00000  r9 : c0a0da28  r8 : 0010004c
[    0.184949] r7 : 7b01e9c3  r6 : 8c6d8f17  r5 : c7850008  r4 : 00100402
[    0.191633] r3 : c011631c  r2 : 00000402  r1 : e3ed1a32  r0 : e3ed1a20
[    0.198320] Flags: nZCv  IRQs on  FIQs off  Mode SVC_32  ISA ARM  Segment none
[    0.205723] Control: 00c5387d  Table: 00004008  DAC: 00000011
[    0.211622] Process swapper (pid: 1, stack limit = 0xc7842208)
[    0.217607] Stack: (0xc7843ed0 to 0xc7844000)
[    0.222109] 3ec0:                                     07a70e31 b63c5dec a88074e5 f9c70f04
[    0.230481] 3ee0: c7843fa4 ffffe000 00000000 a5cd5888 5334f4d9 4659e95c 87702488 c090b5b0
[    0.238854] 3f00: c7843f54 c0901edc c7843f38 c0329c6c c7843f38 c0957004 c7843f38 c0a0da28
[    0.247227] 3f20: 4884659e 95c87702 00000000 00000001 c7844000 27405d72 bcaf5b3e e382a1c7
[    0.255599] 3f40: 3f7fdb43 c0a0da28 c09673e0 c09673f8 c7843fa4 c0902184 00000000 00000000
[    0.263969] 3f60: 00000000 00000000 00000000 00000000 00000000 00000000 da1f1c15 0e39fbfe
[    0.272340] 3f80: c060e7d8 00000000 c060e7d8 00000000 00000000 00000000 00000000 00000000
[    0.280709] 3fa0: 00000000 c060e7e0 00000000 c01072f8 00000000 00000000 00000000 00000000
[    0.289077] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[    0.297446] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000
[    0.305845] [<c0116324>] (v6_flush_kern_dcache_area+0x8/0x24) from [<c090b78c>] (init_static_idmap+0x1dc/0x280)
[    0.316166] [<c090b78c>] (init_static_idmap+0x1dc/0x280) from [<c0901edc>] (do_one_initcall+0x118/0x2d8)
[    0.325867] [<c0901edc>] (do_one_initcall+0x118/0x2d8) from [<c0902184>] (kernel_init_freeable+0xe8/0x3cc)
[    0.335743] [<c0902184>] (kernel_init_freeable+0xe8/0x3cc) from [<c060e7e0>] (kernel_init+0x8/0x118)
[    0.345098] [<c060e7e0>] (kernel_init+0x8/0x118) from [<c01072f8>] (ret_from_fork+0x14/0x3c)
[    0.353739] Code: e3e0000d e12fff1e e0801001 e3c0001f (ee070f3e)
[    0.360034] ---[ end trace c68a38bb56eb9818 ]---
[    0.364802] Kernel panic - not syncing: grsec: halting the system due to suspicious kernel crash caused by root
[    0.375094] ---[ end Kernel panic - not syncing: grsec: halting the system due to suspicious kernel crash caused by root


In both cases (RPI and RPI2) I've used make bcm2835_defconfig + grsecurity automatic configuration (server, security) + early printk

Thanks in advance.

[spender]

Thanks for the update -- can you bisect which grsecurity feature is causing the failure? KERNEXEC/UDEREF/REFCOUNT are probably the only likely culprits.

-Brad

[PaX Team]

can you resolve the LR addresses reported in dmesg to a source line (using addr2line)?

edit: you could also send us vmlinux (from the build root).

[radegand]

Thanks for the hints.
addr2line gives this:

Code: Select all

$ arm-linux-gnueabihf-addr2line -f -e vmlinux c0116598
v7_flush_kern_dcache_area
linux-4.7.4-grsec/arch/arm/mm/cache-v7.S:325

$ arm-linux-gnueabihf-addr2line -f -e vmlinux c090b774
identity_mapping_add
linux-4.7.4-grsec/arch/arm/mm/idmap.c:96


The former is PC, the latter is value from LR.
In case of rpi, it's v6_flush_kern_dcache_area instead of v7_flush_kern_dcache_area, presumably as it's armv6 vs armv7.

Trying to find the culprit, it's not KERNEXEC...

[radegand]

Ok, so it's RANDSTRUCT...I took the liberty to email you the config + vmlinux.

Thanks!

[spender]

Thanks for the report, this should be fixed in the next patch.

-Brad

[radegand]

I can confirm that the patch you have provided fixes the issue - thanks for quick help!

Tested with 4.7.5.