[Letux-kernel] 5.4-rc1 woes

Andreas Kemnade andreas at kemnade.info
Thu Oct 3 11:46:48 CEST 2019


On Thu, 3 Oct 2019 10:47:16 +0200
"H. Nikolaus Schaller" <hns at goldelico.com> wrote:

> > Am 03.10.2019 um 10:44 schrieb Andreas Kemnade <andreas at kemnade.info>:
> > 
> > On Thu, 3 Oct 2019 08:26:46 +0200
> > "H. Nikolaus Schaller" <hns at goldelico.com> wrote:
> >   
> >>> Am 02.10.2019 um 23:16 schrieb Andreas Kemnade <andreas at kemnade.info>:
> >>> 
> >>> On Wed, 2 Oct 2019 22:19:31 +0200
> >>> Andreas Kemnade <andreas at kemnade.info> wrote:
> >>> 
> >>> [..]    
> >>>> # first bad commit: [ac7c3e4ff401b304489a031938dbeaab585bfe0a] compiler: enable CONFIG_OPTIMIZE_INLINING forcibly
> >>>> 
> >>>> hmmmm...
> >>>> Now it depends on compliers?!
> >>>> andi at aktux:~/gta04/gta04-autotest-kernel$ arm-linux-gnueabihf-gcc --version
> >>>> arm-linux-gnueabihf-gcc (Debian 8.3.0-2) 8.3.0
> >>>> Copyright (C) 2018 Free Software Foundation, Inc.
> >>>> This is free software; see the source for copying conditions.  There is NO
> >>>> warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
> >>>> 
> >>>> And how to debug it? Well, lets first check whether reverting that
> >>>> improves things on 5.4-rc1.
> >>>>   
> >>> ok, tested to revert it: I had to disable it in .config afterwards,
> >>> seems to have crept into letux_defconfig.    
> >> 
> >> Was automatically set if undefined...
> >> 
> >> git show f863a359c2b2 | fgrep CONFIG_OPTIMIZE_INLINING
> >> -# CONFIG_OPTIMIZE_INLINING is not set
> >> +CONFIG_OPTIMIZE_INLINING=y
> >>   
> >>> And so weird error messages.    
> >> 
> >> Indeed.
> >>   
> >>> No bad addresses. I guess it somehow incfluences some copy_to_user
> >>> stuff.
> >>> Weird. So where to ask...?    
> >> 
> >> fgrep OPTIMIZE_INLINING -R *
> >> arch/arm/boot/src/FULLCONFIG:CONFIG_OPTIMIZE_INLINING=y
> >> arch/arm/configs/letux_defconfig:CONFIG_OPTIMIZE_INLINING=y
> >> arch/arm/configs/letux_defconfig.bak:CONFIG_OPTIMIZE_INLINING=y
> >> arch/arm/configs/letux_lpae_defconfig:CONFIG_OPTIMIZE_INLINING=y
> >> arch/arm/configs/letux_lpae_defconfig.bak:CONFIG_OPTIMIZE_INLINING=y
> >> arch/arm/configs/omap3_beagle_defconfig:# CONFIG_OPTIMIZE_INLINING is not set
> >> arch/mips/boot/src/CONFIG:# CONFIG_OPTIMIZE_INLINING is not set
> >> arch/mips/boot/src/FULLCONFIG:CONFIG_OPTIMIZE_INLINING=y
> >> arch/mips/configs/letux_defconfig:CONFIG_OPTIMIZE_INLINING=y
> >> arch/sparc/vdso/vdso32/vclock_gettime.c:#undef	CONFIG_OPTIMIZE_INLINING
> >> arch/x86/configs/i386_defconfig:CONFIG_OPTIMIZE_INLINING=y
> >> arch/x86/configs/x86_64_defconfig:CONFIG_OPTIMIZE_INLINING=y
> >> arch/x86/entry/vdso/vdso32/vclock_gettime.c:#undef CONFIG_OPTIMIZE_INLINING
> >> include/linux/compiler_types.h:#if !defined(CONFIG_OPTIMIZE_INLINING)
> >> kernel/configs/tiny.config:CONFIG_OPTIMIZE_INLINING=y
> >> lib/Kconfig.debug:config OPTIMIZE_INLINING
> >> 
> >> So it is defined in lib/Kconfig.debug. Do we still have debugging enabled?
> >>   
> > well, that Kconfig.debug is enabled unconditionally.
> >   
> >> Only minimally:
> >> 
> >> fgrep DEBUG arch/arm/configs/letux_defconfig | fgrep -v '#'
> >> CONFIG_DEBUG_FS=y
> >> CONFIG_HAVE_DEBUG_KMEMLEAK=y
> >> CONFIG_ARCH_HAS_DEBUG_VIRTUAL=y
> >> CONFIG_DEBUG_MEMORY_INIT=y
> >> CONFIG_LOCK_DEBUGGING_SUPPORT=y
> >> CONFIG_DEBUG_BUGVERBOSE=y
> >> CONFIG_DEBUG_LL_INCLUDE="mach/debug-macro.S"
> >> 
> >> It is used in only one place: include/linux/compiler-gcc.h
> >> 
> >> But why was it set automatically? Because the new patch forces it to be so...
> >>   
> >>> Weird.    
> >> 
> >> Indeed.
> >>   
> >>> So where to ask...?    
> >> 
> >> Author: Masahiro Yamada <yamada.masahiro at socionext.com>
> >> 
> >>    I am keeping the config option just in case any problem crops up for other
> >>    architectures.
> >>   
> > well, the answer is not so easy. That option is e.g. enabled on x86_64
> > debian buster kernels. So I am actually writing an email on a kernel
> > with that flag turned on.
> > 
> > So it must be a combination of CONFIGs which
> > trigger some bug in the code (probably arm-specific).
> > Maybe trying omap2plus_defconfig will be interesting.  
> 
> Yes, that is one test I was also thinking of.
> 
seems to work normally. Besides of having aa ttyS2 instead of ttyO2...
ok, now I am enabling CONFIG_PREEMPT. And...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.4.0-rc1 (andi at aktux) (gcc version 8.3.0 (Debian 8.3.0-2)) #3 SMP PREEMPT Thu Oc9
[    0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Goldelico GTA04b2/Letux 3704
[    0.000000] earlycon: omap8250 at MMIO 0x49020000 (options '')
[    0.000000] printk: bootconsole [omap8250] enabled
[    0.000000] Memory policy: Data cache writeback
[    0.000000] cma: Reserved 16 MiB at 0x9e800000
[    0.000000] CPU: All CPU(s) started in SVC mode.
[    0.000000] OMAP3630/DM3730 ES1.2 (l2cache iva sgx neon isp 192mhz_clk)
[    0.000000] percpu: Embedded 19 pages/cpu s49036 r8192 d20596 u77824
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 129412
[    0.000000] Kernel command line: root=/dev/mmcblk0p2 earlycon console=ttyO2,115200n8
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 482412K/522240K available (8192K kernel code, 715K rwdata, 2060K rodata, 1024K init, 25)
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=2 to nr_cpu_ids=1.
[    0.000000]  Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] IRQ: Found an INTC at 0x(ptrval) (revision 4.0) with 96 interrupts
[    0.000000] random: get_random_bytes called from start_kernel+0x2b0/0x4dc with crng_init=0
[    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/400/600 MHz
[    0.000000] OMAP clockevent source: timer1 at 32768 Hz
[    0.000000] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 s
[    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, wraps every 65535999984741ns
[    0.008605] OMAP clocksource: 32k_counter at 32768 Hz
[    0.015167] Console: colour dummy device 80x30
[    0.019775] WARNING: Your 'console=ttyO2' has been replaced by 'ttyS2'
[    0.026519] This ensures that you still see kernel messages. Please
[    0.032989] update your kernel commandline.
[    0.037353] Calibrating delay loop... 597.60 BogoMIPS (lpj=2988032)
[    0.099060] pid_max: default: 32768 minimum: 301
[    0.104064] LSM: Security Framework initializing
[    0.108947] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.116546] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.125946] CPU: Testing write buffer coherency: ok
[    0.131042] CPU0: Spectre v2: using BPIALL workaround
[    0.136810] CPU0: thread -1, cpu 0, socket -1, mpidr 0
[    0.192565] Setting up static identity map for 0x80100000 - 0x80100078
[    0.199584] rcu: Hierarchical SRCU implementation.
[    0.242340] smp: Bringing up secondary CPUs ...
[    0.247009] smp: Brought up 1 node, 1 CPU
[    0.251159] SMP: Total of 1 processors activated (597.60 BogoMIPS).
[    0.257659] CPU: All CPU(s) started in SVC mode.
[    0.263275] devtmpfs: initialized
[    0.302398] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3
[    0.311065] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.321319] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
[    0.329864] pinctrl core: initialized pinctrl subsystem
[    0.337066] NET: Registered protocol family 16
[    0.355682] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.399139] omap_hwmod: mcbsp2_sidetone using broken dt data from mcbsp
[    0.407104] omap_hwmod: mcbsp3_sidetone using broken dt data from mcbsp
[    0.501922] audit: initializing netlink subsys (disabled)
[    0.509002] cpuidle: using governor menu
[    0.513153] audit: type=2000 audit(0.500:1): state=initialized audit_enabled=0 res=1
[    0.521575] Reprogramming SDRC clock to 400000000 Hz
[    0.534729] OMAP GPIO hardware version 2.5
[    0.560485] omap-gpmc 6e000000.gpmc: GPMC revision 5.0
[    0.565887] gpmc_mem_init: disabling cs 0 mapped at 0x0-0x1000000
[    0.583526] No ATAGs?
[    0.583526] hw-breakpoint: debug architecture 0x4 unsupported.
[    0.593780] OMAP DMA hardware revision 5.0
[    0.665710] omap-dma-engine 48056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
[    0.681762] iommu: Default domain type: Translated 
[    0.688751] omap-iommu 480bd400.mmu: 480bd400.mmu registered
[    0.695556] platform 480bc000.isp: Adding to iommu group 0
[    0.703460] vgaarb: loaded
[    0.707000] SCSI subsystem initialized
[    0.713195] omap_i2c 48070000.i2c: bus 0 rev4.4 at 2600 kHz
[    0.721618] i2c i2c-1: of_i2c: modalias failure on /ocp at 68000000/i2c at 48072000/tps61050 at 33
[    0.730041] i2c i2c-1: Failed to create I2C device for /ocp at 68000000/i2c at 48072000/tps61050 at 33
[    0.738891] omap_i2c 48072000.i2c: bus 1 rev4.4 at 400 kHz
[    0.745544] omap_i2c 48060000.i2c: bus 2 rev4.4 at 100 kHz
[    0.751831] pps_core: LinuxPPS API ver. 1 registered
[    0.756958] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti at linux.it>
[    0.766448] PTP clock support registered
[    0.771820] clocksource: Switched to clocksource 32k_counter
[    1.535247] VFS: Disk quotas dquot_6.6.0
[    1.539428] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.562377] thermal_sys: Registered thermal governor 'fair_share'
[    1.562377] thermal_sys: Registered thermal governor 'step_wise'
[    1.568664] thermal_sys: Registered thermal governor 'user_space'
[    1.575622] NET: Registered protocol family 2
[    1.587677] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    1.596496] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    1.604644] TCP bind hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    1.612182] TCP: Hash tables configured (established 4096 bind 4096)
[    1.618865] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    1.625671] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    1.633178] NET: Registered protocol family 1
[    1.669403] RPC: Registered named UNIX socket transport module.
[    1.675659] RPC: Registered udp transport module.
[    1.680511] RPC: Registered tcp transport module.
[    1.685424] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.692077] PCI: CLS 0 bytes, default 64
[    1.699127] Trying to unpack rootfs image as initramfs...
[    2.331512] Freeing initrd memory: 4756K
[    2.337005] hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available
[    2.348358] Initialise system trusted keyrings
[    2.353454] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[    2.372192] NFS: Registering the id_resolver key type
[    2.377441] Key type id_resolver registered
[    2.381744] Key type id_legacy registered
[    2.386047] jffs2: version 2.2. (NAND) (SUMMARY)  �© 2001-2006 Red Hat, Inc.
[    2.393890] Key type asymmetric registered
[    2.398101] Asymmetric key parser 'x509' registered
[    2.403228] io scheduler mq-deadline registered
[    2.407897] io scheduler kyber registered
[    2.419769] pinctrl-single 48002030.pinmux: 284 pins, size 568
[    2.426574] pinctrl-single 48002a00.pinmux: 46 pins, size 92
[    2.433319] pinctrl-single 480025a0.pinmux: 46 pins, size 92
[    2.439697] pinctrl-single 48002274.pinmux_mcbsp1: initialized with no interrupts
[    2.447479] pinctrl-single 48002274.pinmux_mcbsp1: 10 pins, size 4
[    2.454254] pinctrl-single 480022d8.pinmux_tv_out: initialized with no interrupts
[    2.462127] pinctrl-single 480022d8.pinmux_tv_out: 4 pins, size 4
[    2.475616] Serial: 8250/16550 driver, 6 ports, IRQ sharing enabled
[    2.486846] 4806a000.serial: ttyS0 at MMIO 0x4806a000 (irq = 88, base_baud = 3000000) is a 8250
[    2.496307] serial serial0: tty port ttyS0 registered
[    2.502807] 4806c000.serial: ttyS1 at MMIO 0x4806c000 (irq = 89, base_baud = 3000000) is a 8250
[    2.512268] serial serial1: tty port ttyS1 registered
[    2.518646] 49020000.serial: ttyS2 at MMIO 0x49020000 (irq = 90, base_baud = 3000000) is a 8250
[    2.527893] printk: console [ttyS2] enabled
[    2.527893] printk: console [ttyS2] enabled
[    2.536529] printk: bootconsole [omap8250] disabled
[    2.536529] printk: bootconsole [omap8250] disabled
[    2.548339] 49042000.serial: ttyS3 at MMIO 0x49042000 (irq = 96, base_baud = 3000000) is a 8250
[    2.557159] random: fast init done
[    2.580474] brd: module loaded
[    2.598449] loop: module loaded
[    2.636688] twl 0-0048: PIH (irq 23) chaining IRQs 147..155
[    2.642517] twl 0-0048: power (irq 152) chaining IRQs 155..162
[    2.655914] VAUX3: Bringing 2800000uV into 2500000-2500000uV
[    2.676544] VMMC2: Bringing 2600000uV into 1800000-1800000uV
[    2.682647] VMMC2: failed to apply 1800000-1800000uV constraint(-22)
[    2.689056] twl4030_reg 48070000.i2c:twl at 48:regulator-vmmc2: can't register VMMC2, -22
[    2.697082] twl4030_reg: probe of 48070000.i2c:twl at 48:regulator-vmmc2 failed with error -22
[    2.713043] VSIM: Bringing 1800000uV into 2800000-2800000uV
[    2.721405] twl4030_gpio twl4030-gpio: gpio (irq 147) chaining IRQs 163..180
[    2.749938] mtdoops: mtd device (mtddev=name/number) must be supplied
[    2.758300] nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xbc
[    2.764770] nand: Micron MT29F4G16ABBDA3W
[    2.768798] nand: 512 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[    2.776458] omap2-nand 30000000.nand: nand: using OMAP_ECC_HAM1_CODE_HW
[    2.783203] nand: WARNING: omap2-nand.0: the ECC used on your system is too weak compared to the one requirp
[    2.794799] 5 fixed-partitions partitions found on MTD device omap2-nand.0
[    2.801727] Creating 5 MTD partitions on "omap2-nand.0":
[    2.807098] 0x000000000000-0x000000080000 : "X-Loader"
[    2.823455] 0x000000080000-0x000000240000 : "U-Boot"
[    2.843353] 0x000000240000-0x000000280000 : "U-Boot Env"
[    2.863342] 0x000000280000-0x000000880000 : "Kernel"
[    2.883331] 0x000000880000-0x000020000000 : "File System"
[    3.109069] libphy: Fixed MDIO Bus: probed
[    3.116912] i2c /dev entries driver
[    3.125427] sdhci: Secure Digital Host Controller Interface driver
[    3.131652] sdhci: Copyright(c) Pierre Ossman
[                         
and ... nothing. So that kernel option triggered a CONFIG_PREEMPT-related bug.
Hmm, no mmc. so maybe a mmc+CONFIG_PREEMPT related bug triggered by that kernel option.


Regards,
Andreas


More information about the Letux-kernel mailing list